open-telemetry / opentelemetry-cpp

The OpenTelemetry C++ Client
https://opentelemetry.io/
Apache License 2.0
851 stars 406 forks source link

ElasticSearch exporter crashes when emitting a log (EXC_BAD_ACCESS) #3078

Open MaxLeb opened 4 days ago

MaxLeb commented 4 days ago

Describe your environment

Using a manually built version of OpenTelemetry 1.16.1 on macOS with :

    -DWITH_EXAMPLES=OFF
    -DWITH_OTLP_HTTP=ON
    -DBUILD_TESTING=OFF
    -DWITH_OTLP_GRPC=OFF
    -DWITH_LOGS_PREVIEW=ON
    -DOPENTELEMETRY_INSTALL=ON
    -DBUILD_SHARED_LIBS=OFF
    -DWITH_ASYNC_EXPORT_PREVIEW=ON
    -DCMAKE_CXX_STANDARD=17
    -DWITH_ELASTICSEARCH=ON

Steps to reproduce

The usage is pretty simple:

First an init of the exporter with a single log record processor:

opentelemetry::exporter::logs::ElasticsearchExporterOptions opts(
    <host>,
    9200,
    "logs",
    30,
    true);

auto elkExporter = std::make_unique<opentelemetry::exporter::logs::ElasticsearchLogRecordExporter>(opts);

auto elkProcessor = opentelemetry::sdk::logs::SimpleLogRecordProcessorFactory::Create(std::move(elkExporter));

std::shared_ptr<opentelemetry::logs::LoggerProvider> provider = opentelemetry::sdk::logs::LoggerProviderFactory::Create(
    std::move(elkProcessor), resource);

opentelemetry::logs::Provider::SetLoggerProvider(provider);

m_Logger = provider->GetLogger("MyLogger", SOURCE_NAME);

Then, when logs needs to be sent a call to m_Logger.EmitLogRecord(xxx)

What is the expected behavior? The program should run and send the log to the ELK endpoint.

What is the actual behavior? It crashes on es_log_record_exporter.cc:353

 thread #5, stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
    frame #0: 0x00000001011d2e44 `unsigned long std::__1::__cxx_atomic_fetch_add<unsigned long>(__a=0x0000000000000000, __delta=1, __order=memory_order_release) at atomic:1050:12
   1047 template<class _Tp>
   1048 _LIBCPP_INLINE_VISIBILITY
   1049 _Tp __cxx_atomic_fetch_add(__cxx_atomic_base_impl<_Tp> * __a, _Tp __delta, memory_order __order) _NOEXCEPT {
-> 1050     return __c11_atomic_fetch_add(&__a->__a_value, __delta, static_cast<__memory_order_underlying_t>(__order));
   1051 }
   1052
   1053 template<class _Tp>

Backtrace:

frame #0: 0x00000001011d2e44 `unsigned long std::__1::__cxx_atomic_fetch_add<unsigned long>(__a=0x0000000000000000, __delta=1, __order=memory_order_release) at atomic:1050:12
frame #1: 0x00000001011c06ec `std::__1::__atomic_base<unsigned long, true>::fetch_add(this=0x0000000000000000, __op=1, __m=memory_order_release) at atomic:1719:17
frame #2: 0x00000001011bfedc `opentelemetry::v1::exporter::logs::ElasticsearchLogRecordExporter::Export(this=0x000060000079bf80, records=0x000000017002a960) at es_log_record_exporter.cc:353:43
frame #3: 0x0000000101214f08 `opentelemetry::v1::sdk::logs::SimpleLogRecordProcessor::OnEmit(this=0x00006000029c1d20, record=nullptr) at simple_log_record_processor.cc:48:18
frame #4: 0x0000000101227b40 `opentelemetry::v1::sdk::logs::MultiLogRecordProcessor::OnEmit(this=0x00006000029c1d40, record=opentelemetry::v1::sdk::logs::Recordable @ 0x00006000027a0de0) at multi_log_record_processor.cc:70:18
frame #5: 0x000000010120be40 `opentelemetry::v1::sdk::logs::Logger::EmitLogRecord(this=0x0000600003c9c440, log_record=0x000000017002ab50) at logger.cc:109:13
frame #6: 0x0000000100b63bc0 `void opentelemetry::v1::logs::Logger::EmitLogRecord<opentelemetry::v1::logs::Severity, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >&, std::__1::map<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::less<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > >, std::__1::allocator<std::__1::pair<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > >&, opentelemetry::v1::common::SystemTimestamp>(this=0x0000600003c9c440, log_record=0x000000017002ab50, args=0x000000017002abf7, args=Summary Unavailable, args=size=0, args=0x000000017002abe8) at logger.h:79:5

Additional context There is no problem if using a HttpLogRecordExporter instead of a ElasticsearchLogRecordExporter with the exact samecode

marcalff commented 4 days ago

According to the trace, this line at exporters/elasticsearch/src/es_log_record_exporter.cc:353, crashes with a nullptr:

  synchronization_data_->session_counter_.fetch_add(1, std::memory_order_release);
MaxLeb commented 3 days ago

I think I found the issue.

I will test it as soon as I can but I am using the constructor:


ElasticsearchLogRecordExporter::ElasticsearchLogRecordExporter(
    const ElasticsearchExporterOptions &options)
    : options_{options}, http_client_{ext::http::client::HttpClientFactory::Create()}
{}

and it never calls the other constructor that initiate the synchronization_data_ :

ElasticsearchLogRecordExporter::ElasticsearchLogRecordExporter()
    : options_{ElasticsearchExporterOptions()},
      http_client_{ext::http::client::HttpClientFactory::Create()}
#ifdef ENABLE_ASYNC_EXPORT
      ,
      synchronization_data_(new SynchronizationData())
#endif
{
#ifdef ENABLE_ASYNC_EXPORT
  synchronization_data_->finished_session_counter_.store(0);
  synchronization_data_->session_counter_.store(0);
#endif
}

I will test to fix it and probably submit a PR or at least a patch here if I do not have time to properly create the PR.

MaxLeb commented 3 days ago

As expected, fixing the code fixes the crash. Here is a patch that makes it work, will try to provide a proper PR

0001-EXPORTER-Fix-crash-in-ElasticsearchLogRecordExporter.patch

marcalff commented 2 days ago

Thanks, synchronization_data_ was obviously missing.

Please file a PR for this.