heap-use-after-free with BatchLogRecordProcessor #3135
Description
Describe your environment
OpenTelemetry v1.17.0
Steps to reproduce
Sample code: https://github.com/sjinks/otel-heap-use-after-free
Sample run: https://github.com/sjinks/otel-heap-use-after-free/actions/runs/11758831588/job/32757617053
What is the expected behavior?
There should be no errors.
What is the actual behavior?
The application crashed because of the heap-use-after-free-error
=5853==ERROR: AddressSanitizer: heap-use-after-free on address 0x6030000005c8 at pc 0x55707b183c86 bp 0x7f82e12fe770 sp 0x7f82e12fdf38
READ of size 6 at 0x6030000005c8 thread T1
#0 0x55707b183c85 in __interceptor_strlen (/home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/build/bug-repro+0x46c85) (BuildId: 3dbd37ecfe9134972fe6a448909a1b651fdd1e62)
#1 0x7f82e3b3ceac in std::basic_ostream<char, std::char_traits<char> >& std::operator<<<std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*) (/lib/x86_64-linux-gnu/libstdc++.so.6+0x13ceac) (BuildId: e37fe1a879783838de78cbc8c80621fa685d58a2)
#2 0x55707b247a33 in void opentelemetry::v1::exporter::ostream_common::print_value<char const*>(char const* const&, std::ostream&) /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/exporters/ostream/include/opentelemetry/exporters/ostream/common_utils.h:25:8
#3 0x55707b2435cb in auto opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&, std::ostream&)::'lambda'(auto&&)::operator()<char const* const&>(auto&&) const /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.
#4 0x55707b24ab4d in auto std::__invoke_impl<void, opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&, std::ostream&)::'lambda'(auto&&), char const* const&>(std::__invoke_other, opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, doub
#5 0x55707b248277 in std::__invoke_result<auto, char const* const&>::type std::__invoke<opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&, std::ostream&)::'lambda'(auto&&), char const* const&>(auto&&, char const* const&) /usr/include/c++/11/bits/invoke.h:96:40
#6 0x55707b243a33 in std::__detail::__variant::__gen_vtable_impl<std::__detail::__variant::_Multi_array<std::__detail::__variant::__deduce_visit_result<void> (*)(opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&, std::ostream&)::'lambda'(auto&&)&&, std::variant<bool, int, long, uns
#7 0x55707b243f3a in decltype(auto) std::__do_visit<std::__detail::__variant::__deduce_visit_result<void>, opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&, std::ostream&)::'lambda'(auto&&), std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd:
#8 0x55707b243fa1 in std::invoke_result<auto, std::conditional<is_lvalue_reference_v<std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&>, std::variant_alternative<0ul, std::remove_reference<decltype(__as(declval<std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd
#9 0x55707b23f9a8 in opentelemetry::v1::exporter::ostream_common::print_value(std::variant<bool, int, long, unsigned int, double, char const*, opentelemetry::v1::nostd::string_view, opentelemetry::v1::nostd::span<bool const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned int const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<double const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<opentelemetry::v1::nostd::string_view const, 18446744073709551615ul>, unsigned long, opentelemetry::v1::nostd::span<unsigned long const, 18446744073709551615ul>, opentelemetry::v1::nostd::span<unsigned char const, 18446744073709551615ul> > const&, std::ostream&) /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/exporters/ostream/include/opentelemetry/exporters/ostream/commo
#10 0x55707b23e5a4 in opentelemetry::v1::exporter::logs::OStreamLogRecordExporter::Export(opentelemetry::v1::nostd::span<std::unique_ptr<opentelemetry::v1::sdk::logs::Recordable, std::default_delete<opentelemetry::v1::sdk::logs::Recordable> >, 18446744073709551615ul> const&) /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/exporters/ostream/src/log_record_exporter.cc:111:57
#11 0x55707b276fe7 in opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::Export() /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/sdk/src/logs/batch_log_record_processor.cc:223:22
#12 0x55707b276cc6 in opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::DoBackgroundWork() /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/sdk/src/logs/batch_log_record_processor.cc:178:11
#13 0x55707b27c429 in void std::__invoke_impl<void, void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*>(std::__invoke_memfun_deref, void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*&&)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*&&) /usr/include/c++/11/bits/invoke.h:74:46
#14 0x55707b27c37c in std::__invoke_result<void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*>::type std::__invoke<void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*>(void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*&&)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*&&) /usr/include/c++/11/bits/invoke.h:96:40
#15 0x55707b27c2dc in void std::thread::_Invoker<std::tuple<void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/include/c++/11/bits/std_thread.h:259:26
#16 0x55707b27c22b in std::thread::_Invoker<std::tuple<void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*> >::operator()() /usr/include/c++/11/bits/std_thread.h:266:20
#17 0x55707b27c1c3 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::*)(), opentelemetry::v1::sdk::logs::BatchLogRecordProcessor*> > >::_M_run() /usr/include/c++/11/bits/std_thread.h:211:20
#18 0x7f82e3adc252 (/lib/x86_64-linux-gnu/libstdc++.so.6+0xdc252) (BuildId: e37fe1a879783838de78cbc8c80621fa685d58a2)
#19 0x7f82e3694ac2 (/lib/x86_64-linux-gnu/libc.so.6+0x94ac2) (BuildId: 490fef8403240c91833978d494d39e537409b92e)
#20 0x7f82e372684f (/lib/x86_64-linux-gnu/libc.so.6+0x12684f) (BuildId: 490fef8403240c91833978d494d39e537409b92e)
0x6030000005c8 is located 24 bytes inside of 30-byte region [0x6030000005b0,0x6030000005ce)
freed by thread T0 here:
#0 0x55707b22bfbd in operator delete(void*) (/home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/build/bug-repro+0xeefbd) (BuildId: 3dbd37ecfe9134972fe6a448909a1b651fdd1e62)
#1 0x7f82e3ac46f2 in std::runtime_error::~runtime_error() (/lib/x86_64-linux-gnu/libstdc++.so.6+0xc46f2) (BuildId: e37fe1a879783838de78cbc8c80621fa685d58a2)
#2 0x7f82e3629d8f (/lib/x86_64-linux-gnu/libc.so.6+0x29d8f) (BuildId: 490fef8403240c91833978d494d39e537409b92e)
previously allocated by thread T0 here:
#0 0x55707b22b75d in operator new(unsigned long) (/home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/build/bug-repro+0xee75d) (BuildId: 3dbd37ecfe9134972fe6a448909a1b651fdd1e62)
#1 0x7f82e3af4978 in std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (/lib/x86_64-linux-gnu/libstdc++.so.6+0xf4978) (BuildId: e37fe1a879783838de78cbc8c80621fa685d58a2)
Thread T1 created by T0 here:
#0 0x55707b1d9e0c in __interceptor_pthread_create (/home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/build/bug-repro+0x9ce0c) (BuildId: 3dbd37ecfe9134972fe6a448909a1b651fdd1e62)
#1 0x7f82e3adc328 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) (/lib/x86_64-linux-gnu/libstdc++.so.6+0xdc328) (BuildId: e37fe1a879783838de78cbc8c80621fa685d58a2)
#2 0x55707b2764d0 in opentelemetry::v1::sdk::logs::BatchLogRecordProcessor::BatchLogRecordProcessor(std::unique_ptr<opentelemetry::v1::sdk::logs::LogRecordExporter, std::default_delete<opentelemetry::v1::sdk::logs::LogRecordExporter> >&&, opentelemetry::v1::sdk::logs::BatchLogRecordProcessorOptions const&) /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/sdk/src/logs/batch_log_record_processor.cc:58:7
#3 0x55707b26c501 in opentelemetry::v1::sdk::logs::BatchLogRecordProcessorFactory::Create(std::unique_ptr<opentelemetry::v1::sdk::logs::LogRecordExporter, std::default_delete<opentelemetry::v1::sdk::logs::LogRecordExporter> >&&, opentelemetry::v1::sdk::logs::BatchLogRecordProcessorOptions const&) /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/vcpkg/buildtrees/opentelemetry-cpp/src/v1.17.0-b9ea5cab17.clean/sdk/src/logs/batch_log_record_processor_factory.cc:25:63
#4 0x55707b22e18b in main /home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/repro.cpp:19:22
#5 0x7f82e3629d8f (/lib/x86_64-linux-gnu/libc.so.6+0x29d8f) (BuildId: 490fef8403240c91833978d494d39e537409b92e)
SUMMARY: AddressSanitizer: heap-use-after-free (/home/runner/work/otel-heap-use-after-free/otel-heap-use-after-free/build/bug-repro+0x46c85) (BuildId: 3dbd37ecfe9134972fe6a448909a1b651fdd1e62) in __interceptor_strlen
Shadow bytes around the buggy address:
0x0c067fff8060: fa fa fd fd fd fa fa fa fd fd fd fa fa fa fd fd
0x0c067fff8070: fd fa fa fa fd fd fd fa fa fa fd fd fd fa fa fa
0x0c067fff8080: fd fd fd fa fa fa 00 00 06 fa fa fa 00 00 03 fa
0x0c067fff8090: fa fa 00 00 07 fa fa fa 00 00 00 00 fa fa 00 00
0x0c067fff80a0: 00 fa fa fa 00 00 00 fa fa fa fd fd fd fa fa fa
=>0x0c067fff80b0: fd fd fd fa fa fa fd fd fd[fd]fa fa 00 00 00 fa
0x0c067fff80c0: fa fa fd fd fd fa fa fa fd fd fd fa fa fa fd fd
0x0c067fff80d0: fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c067fff80e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c067fff80f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c067fff8100: 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
==5853==ABORTING
Additional context
opentelemetry::sdk::logs::BatchLogRecordProcessorOptions options{2048, std::chrono::milliseconds(5000), 512};
auto processor = opentelemetry::sdk::logs::BatchLogRecordProcessorFactory::Create(std::move(exporter), options);
//...
try {
throw std::runtime_error("error");
}
catch (const std::exception &e) {
auto logger = opentelemetry::logs::Provider::GetLoggerProvider()->GetLogger("example");
logger->Error(e.what());
}The bug happens when the catch block is left before the BatchLogRecordProcessor processes the data.
My understanding is that the log message is stored ReadWriteLogRecord::body_ which is opentelemetry::common::AttributeValue, a nostd::variant holding a const char* value. When e goes out of the scope and gets destructed, the memory pointed to by e.what() is also freed. However, because AttributeValue does not own the data, it is left with a dangling pointer.
The fix will probably be to replace AttributeValue with OwnedAttributeValue (this will affect body_ and attributes_map_).
Refs: