trompeloeil icon indicating copy to clipboard operation
trompeloeil copied to clipboard
verified publisher icon rollbear

Strange problems (SIGSEGV) with new version, was working fine with v32

Open FreddieChopin opened this issue 4 years ago • 3 comments

So I have an embedded project for which I've added some unit tests using catch2 and trompeloeil (v32) and this has worked fine for a long time. https://github.com/DISTORTEC/distortos

Today I tried to update both trompeloeil and catch2, because my new compiler had some issues with catch2. After updating and adding the new sendOk() reporter (copied from the trompeloeil repo), I've noticed that I can no longer build the tests. When I start the compilation, the whole system freezes after maybe 10-15 seconds. After checking in system monitor, it seems that the compilation quickly eats up all the RAM available on my PC (and I have 16 GB).

If I remove send_ok_report() from trompeloeil and edit the only place that calls this function, whole thing builds fine and uses no more than ~5 GB of RAM memory during the process.

Am I doing something wrong here? If not, maybe we could have this new feature inside #ifdef ... #endif and enabled only if user requests that?

I'm on ArchLinux (5.16.9) and I use gcc 11.2.0. Let me know if any more details could be useful here.

FreddieChopin avatar Mar 10 '22 16:03 FreddieChopin

Thank you for the link to your project and the summary of your issue.

I would like to reproduce this locally. It would be helpful if you confirm the following:

  • Confirm version on catch2 used, my guess is 2.13.8.
  • Version of trompeloeil causing the issue, my guess is >= v36.
  • Confirm using libstdc++-v3 as Standard C++ Library.
  • Compiler command line standard mode (-std=c++??).

In the meantime, in my projects I sometimes copy and customize the example code provided in the trompeloeil/include/catch2/trompeloeil.hpp header. Perhaps you could do the same by copying this file and commenting out the function template reporter<specialized>::sendOk()

#if 0
  template <>
  inline void reporter<specialized>::sendOk(
    const char* trompeloeil_mock_calls_done_correctly)
  {      
#ifdef CATCH_CONFIG_PREFIX_ALL
      CATCH_REQUIRE(trompeloeil_mock_calls_done_correctly != 0);
#else
      REQUIRE(trompeloeil_mock_calls_done_correctly != 0);
#endif
  }
#endif

Then include this modified file instead of <catch2/trompeloeil.hpp>.

If no partial-specialization is implemented, the compiler chooses the implementation in the primary function template, https://github.com/rollbear/trompeloeil/blob/main/include/trompeloeil.hpp#L989 .

This default results in a call to a do-nothing implementation, https://github.com/rollbear/trompeloeil/blob/main/include/trompeloeil.hpp#L866 .

I hope this approach helps.

AndrewPaxie avatar Mar 12 '22 00:03 AndrewPaxie

One detail I notice is that send_ok_report() accepts a std::string const&, and passes it to reporter<T>::sendOk() as a c-string. But the only call to send_ok_report() passes a call_matcher's name, and call_matcher_base::name is a const char*. So for every expectation, a std::string is constructed from a c-string, only so that the c-string can be obtained and compared to nullptr. Not sure if this extra work is what's causing the memory consumption, but it seems very unnecessary. Going const char* all the way would be better regardless. It could be changed to not have any arguments at all, but that would be a breaking change since reporter<T>::sendOk() is a documented customization point.

rollbear avatar Mar 13 '22 13:03 rollbear

Confirm version on catch2 used, my guess is 2.13.8.

Yes.

Confirm using libstdc++-v3 as Standard C++ Library.

Yes, this is a standard gcc installation with no additional tricks.

Compiler command line standard mode (-std=c++??).

C++17

Now for the tricky parts (; I've retried my tests with all the trompeloeil versions between the most recent one (42) and the one that I had working previously (32). And I can no longer reproduce my original issue /; Maybe it was some strange fluke or whatever... My rough observations show that building my tests with version 32 uses about 4.8 GB of memory at the peak moment (compilation with 8 threads) and for version 34 (the one where sendOk was introduced) it jumps up by about 500-700 MB, to 5.5 GB at the peak. My tests also use coverage testing, which contributes to about 50% of that memory usage, because if I disable it, the used memory drops to maybe 3 GB at the peak.

But now I've observed another strange behavior - starting from version 39 one of my tests produces following result:

[28/129] C-API-ConditionVariable-unit-test-0

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
C-API-ConditionVariable-unit-test-0 is a Catch v2.13.8 host application.
Run with -? for options

-------------------------------------------------------------------------------
Testing distortos_ConditionVariable_destruct()
-------------------------------------------------------------------------------
/home/freddie/Elektronika/ARM/Projects/distortos/unit-test/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0.cpp:41
...............................................................................

/home/freddie/Elektronika/ARM/Projects/distortos/unit-test/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0.cpp:41: FAILED:
  {Unknown expression after the reported line}
due to a fatal error condition:
  SIGSEGV - Segmentation violation signal

===============================================================================
test cases:  2 |  1 passed | 1 failed
assertions: 12 | 11 passed | 1 failed

FAILED: C-API-ConditionVariable-unit-test/CMakeFiles/run-C-API-ConditionVariable-unit-test-0 /home/freddie/Elektronika/ARM/Projects/distortos/unit-test/output/C-API-ConditionVariable-unit-test/CMakeFiles/run-C-API-ConditionVariable-unit-test-0

If I remove this particular test case ( https://github.com/DISTORTEC/distortos/blob/master/unit-test/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0.cpp#L41 ), then another one fails with the same message. Both of them are using trompeloeil::deathwatched, so it seems that this particular feature has something to do with it.

Looking at the release notes for this version - https://github.com/rollbear/trompeloeil/releases/tag/v39 - may this have something to do with issue #197 ?

FreddieChopin avatar Mar 13 '22 16:03 FreddieChopin

I tried this with latest trompeloeil.hpp from main, and latest distortos from master. When build with -fsanitize=address,undefined, the test program C-API-ConditionVariable-unit-test-0 get a use-after-free report from ASAN.

bjorn@protopteryx /t/1> ./C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0
/home/bjorn/develop/distortos/unit-test/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0.cpp:58:1: runtime error: member call on address 0x7fff6f0d69c0 which does not point to an object of type 'deathwatched'
0x7fff6f0d69c0: note: object is of type 'distortos::ConditionVariable'
 4a 56 00 00  90 9c 56 1e 4a 56 00 00  10 9e 56 1e 4a 56 00 00  c8 69 0d 6f ff 7f 00 00  c8 69 0d 6f
              ^~~~~~~~~~~~~~~~~~~~~~~
              vptr for 'distortos::ConditionVariable'
=================================================================
==16926==ERROR: AddressSanitizer: heap-use-after-free on address 0x607000001bb0 at pc 0x564a1df0281c bp 0x7fff6f0d6100 sp 0x7fff6f0d60f0
READ of size 8 at 0x607000001bb0 thread T0
    #0 0x564a1df0281b in trompeloeil::deathwatched<distortos::ConditionVariable>::~deathwatched() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x77c81b)
    #1 0x564a1deb234d in C_A_T_C_H_T_E_S_T_3() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x72c34d)
    #2 0x564a1e04f9db in Catch::TestInvokerAsFunction::invoke() const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8c99db)
    #3 0x564a1e049fc5 in Catch::TestCase::invoke() const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8c3fc5)
    #4 0x564a1e026e58 in Catch::RunContext::invokeActiveTestCase() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8a0e58)
    #5 0x564a1e0253f6 in Catch::RunContext::runCurrentTest(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x89f3f6)
    #6 0x564a1e019bfc in Catch::RunContext::runTest(Catch::TestCase const&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x893bfc)
    #7 0x564a1e03207f in Catch::(anonymous namespace)::TestGroup::execute() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8ac07f)
    #8 0x564a1e03a842 in Catch::Session::runInternal() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8b4842)
    #9 0x564a1e038deb in Catch::Session::run() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8b2deb)
    #10 0x564a1e19683f in int Catch::Session::run<char>(int, char const* const*) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0xa1083f)
    #11 0x564a1e0b8992 in main (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x932992)
    #12 0x7f42c4c49d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
    #13 0x7f42c4c49e3f in __libc_start_main_impl ../csu/libc-start.c:392
    #14 0x564a1deaf3f4 in _start (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x7293f4)

0x607000001bb0 is located 0 bytes inside of 72-byte region [0x607000001bb0,0x607000001bf8)
freed by thread T0 here:
    #0 0x7f42c586722f in operator delete(void*, unsigned long) ../../../../src/libsanitizer/asan/asan_new_delete.cpp:172
    #1 0x564a1dee2aec in trompeloeil::lifetime_monitor::~lifetime_monitor() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x75caec)
    #2 0x564a1df18d86 in std::default_delete<trompeloeil::expectation>::operator()(trompeloeil::expectation*) const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x792d86)
    #3 0x564a1df01e9a in std::unique_ptr<trompeloeil::expectation, std::default_delete<trompeloeil::expectation> >::~unique_ptr() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x77be9a)
    #4 0x564a1deb224e in C_A_T_C_H_T_E_S_T_3() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x72c24e)
    #5 0x564a1e04f9db in Catch::TestInvokerAsFunction::invoke() const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8c99db)
    #6 0x564a1e049fc5 in Catch::TestCase::invoke() const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8c3fc5)
    #7 0x564a1e026e58 in Catch::RunContext::invokeActiveTestCase() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8a0e58)
    #8 0x564a1e0253f6 in Catch::RunContext::runCurrentTest(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x89f3f6)
    #9 0x564a1e019bfc in Catch::RunContext::runTest(Catch::TestCase const&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x893bfc)
    #10 0x564a1e03207f in Catch::(anonymous namespace)::TestGroup::execute() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8ac07f)
    #11 0x564a1e03a842 in Catch::Session::runInternal() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8b4842)
    #12 0x564a1e038deb in Catch::Session::run() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8b2deb)
    #13 0x564a1e19683f in int Catch::Session::run<char>(int, char const* const*) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0xa1083f)
    #14 0x564a1e0b8992 in main (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x932992)
    #15 0x7f42c4c49d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58

previously allocated by thread T0 here:
    #0 0x7f42c58661c7 in operator new(unsigned long) ../../../../src/libsanitizer/asan/asan_new_delete.cpp:99
    #1 0x564a1df03a35 in std::_MakeUniq<trompeloeil::lifetime_monitor>::__single_object std::make_unique<trompeloeil::lifetime_monitor, trompeloeil::deathwatched<distortos::ConditionVariable>&, char const (&) [22], char const (&) [43], char const (&) [37], trompeloeil::location>(trompeloeil::deathwatched<distortos::ConditionVariable>&, char const (&) [22], char const (&) [43], char const (&) [37], trompeloeil::location&&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x77da35)
    #2 0x564a1deb1b5f in C_A_T_C_H_T_E_S_T_3() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x72bb5f)
    #3 0x564a1e04f9db in Catch::TestInvokerAsFunction::invoke() const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8c99db)
    #4 0x564a1e049fc5 in Catch::TestCase::invoke() const (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8c3fc5)
    #5 0x564a1e026e58 in Catch::RunContext::invokeActiveTestCase() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8a0e58)
    #6 0x564a1e0253f6 in Catch::RunContext::runCurrentTest(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x89f3f6)
    #7 0x564a1e019bfc in Catch::RunContext::runTest(Catch::TestCase const&) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x893bfc)
    #8 0x564a1e03207f in Catch::(anonymous namespace)::TestGroup::execute() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8ac07f)
    #9 0x564a1e03a842 in Catch::Session::runInternal() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8b4842)
    #10 0x564a1e038deb in Catch::Session::run() (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x8b2deb)
    #11 0x564a1e19683f in int Catch::Session::run<char>(int, char const* const*) (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0xa1083f)
    #12 0x564a1e0b8992 in main (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x932992)
    #13 0x7f42c4c49d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58

SUMMARY: AddressSanitizer: heap-use-after-free (/tmp/1/C-API-ConditionVariable-unit-test/C-API-ConditionVariable-unit-test-0+0x77c81b) in trompeloeil::deathwatched<distortos::ConditionVariable>::~deathwatched()
Shadow bytes around the buggy address:
  0x0c0e7fff8320: fa fa 00 00 00 00 00 00 00 00 00 02 fa fa fa fa
  0x0c0e7fff8330: 00 00 00 00 00 00 00 00 07 fa fa fa fa fa 00 00
  0x0c0e7fff8340: 00 00 00 00 00 00 00 04 fa fa fa fa fd fd fd fd
  0x0c0e7fff8350: fd fd fd fd fd fa fa fa fa fa fd fd fd fd fd fd
  0x0c0e7fff8360: fd fd fd fa fa fa fa fa 00 00 00 00 00 00 00 00
=>0x0c0e7fff8370: 00 00 fa fa fa fa[fd]fd fd fd fd fd fd fd fd fa
  0x0c0e7fff8380: fa fa fa fa fd fd fd fd fd fd fd fd fd fa fa fa
  0x0c0e7fff8390: fa fa 00 00 00 00 00 00 00 00 06 fa fa fa fa fa
  0x0c0e7fff83a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c0e7fff83b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c0e7fff83c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==16926==ABORTING

I get the impression that the local variable is destroyed explicitly by distortos magic, and then when it goes out of scope, it's destroyed again.

I did a very ugly work-around, by allocating the object on the heap instead, and explicitly deallocating only the memory, and then ASAN was happy:

TEST_CASE("Testing distortos_ConditionVariable_destruct()", "[destruct]")
{
	distortos::FromCApiMock fromCApiMock;
	auto conditionVariableMock = new trompeloeil::deathwatched<distortos::ConditionVariable> 
	{
			distortos::ConditionVariable::UnitTestTag{}
	};
	distortos_ConditionVariable conditionVariable;

	REQUIRE(distortos_ConditionVariable_destruct(nullptr) == EINVAL);

	{
		REQUIRE_CALL(fromCApiMock,
				getConditionVariable(_)).LR_WITH(&_1 == &conditionVariable).LR_RETURN(std::ref(*conditionVariableMock));
		REQUIRE_DESTRUCTION(*conditionVariableMock);
		REQUIRE(distortos_ConditionVariable_destruct(&conditionVariable) == 0);
	}
	operator delete( (void*)conditionVariableMock);
}

rollbear avatar Aug 19 '22 20:08 rollbear

@FreddieChopin do you have information that still points to this being a bug in Trompeloeil? If not, I intend to close this soon.

rollbear avatar Sep 13 '22 15:09 rollbear

Closing now. Feel free to reopen if you think this was in error.

rollbear avatar Sep 18 '22 10:09 rollbear