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

Fix GlobalLogHandler singleton creation order #1767

Merged
merged 3 commits into from
Nov 14, 2022

Conversation

lalitb
Copy link
Member

@lalitb lalitb commented Nov 14, 2022

Fixes #1718

Changes

GlobalLogHandler and MeterProvider are lazy singletons. As of now, MeterProvider singleton is first initialized, followed by GlobalLogHandler (when the first message is logged). This order of initialization means GlobalLogHandler is destroyed before MeterProvider, which further results in segfault when trying to use the logger from MeterProvider destructor.

The easy solution would be to use GlobalLogHandler to log message from inside the MeterProvider constructor. This makes the complier to guarantee that the GlobalLogHandler is constructed before MeterProvider, and so destroyed after MeterProvider. Have tested the changes locally by reproducing the segfault, and then ensuring there is no segfault with the change.

To demonstrate the order of initialization, refer to the sample code here - https://godbolt.org/z/K8x1dcPW5

The order of initiation and destruction in sample is:

Log::Log
MeterProvider
MeterProvider::ForceFlush
~MeterProvider
~Log::Log

And order of initialization and destruction after replacing line 32 with std::cout << "MeterProvider\n" in the sample code is:

MeterProvider
Log::Log
MeterProvider::ForceFlush
~Log::Log
~MeterProvider

Please provide a brief description of the changes here.

For significant contributions please make sure you have completed the following items:

  • CHANGELOG.md updated for non-trivial changes
  • Unit tests have been added
  • Changes in public API reviewed

@lalitb lalitb requested a review from a team November 14, 2022 05:20
@lalitb lalitb changed the title fix log handler creation order Fix GlobalLogHandler singleton creation order Nov 14, 2022
@codecov
Copy link

codecov bot commented Nov 14, 2022

Codecov Report

Merging #1767 (ad0415c) into main (389b84f) will decrease coverage by 0.06%.
The diff coverage is 100.00%.

Additional details and impacted files

Impacted file tree graph

@@            Coverage Diff             @@
##             main    #1767      +/-   ##
==========================================
- Coverage   85.79%   85.74%   -0.05%     
==========================================
  Files         171      171              
  Lines        5212     5214       +2     
==========================================
- Hits         4471     4470       -1     
- Misses        741      744       +3     
Impacted Files Coverage Δ
...lude/opentelemetry/sdk/common/global_log_handler.h 72.23% <ø> (ø)
sdk/src/metrics/meter_provider.cc 91.18% <100.00%> (+0.27%) ⬆️
sdk/src/trace/tracer_provider.cc 77.28% <100.00%> (+0.53%) ⬆️
ext/src/http/client/curl/http_client_curl.cc 80.31% <0.00%> (-1.13%) ⬇️

Copy link
Member

@marcalff marcalff left a comment

Choose a reason for hiding this comment

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

Looks ok to me.

Please also fix this comment:

/**
 * We can not decide the destroying order of signaltons.
 * Which means, the destructors of other singletons (GlobalLogHandler,TracerProvider and etc.)
 * may be called after destroying of global LogHandler and use OTEL_INTERNAL_LOG_* in it.We can do
 * nothing but ignore the log in this situation.
 */
#define OTEL_INTERNAL_LOG_DISPATCH(level, message, attributes)                            \

@lalitb
Copy link
Member Author

lalitb commented Nov 14, 2022

Looks ok to me.

Please also fix this comment:

/**
 * We can not decide the destroying order of signaltons.
 * Which means, the destructors of other singletons (GlobalLogHandler,TracerProvider and etc.)
 * may be called after destroying of global LogHandler and use OTEL_INTERNAL_LOG_* in it.We can do
 * nothing but ignore the log in this situation.
 */
#define OTEL_INTERNAL_LOG_DISPATCH(level, message, attributes)                            \

Good point, have rephrased the comment now.

@@ -26,6 +27,7 @@ LoggerProvider::LoggerProvider(std::unique_ptr<LogRecordProcessor> &&processor,
std::vector<std::unique_ptr<LogRecordProcessor>> processors;
processors.emplace_back(std::move(processor));
context_ = std::make_shared<sdk::logs::LoggerContext>(std::move(processors), std::move(resource));
OTEL_INTERNAL_LOG_DEBUG("[LoggerProvider] LoggerProvider created.");
Copy link
Contributor

Choose a reason for hiding this comment

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

How about other ctors? Didn't add the log there because they are not used by lazy singleton pattern? Probably add the log for consistency as the log message is provider instance created.

Copy link
Member Author

@lalitb lalitb Nov 14, 2022

Choose a reason for hiding this comment

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

You mean to enhance our debug logging in general by adding logs in all the constructors? That's good feedback, will create a separate issue for it, as it is not directly related to this fix.

Copy link
Member

Choose a reason for hiding this comment

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

How about other ctors? Didn't add the log there because they are not used by lazy singleton pattern? Probably add the log for consistency as the log message is provider instance created.

The per signal singletons are the entry points to the SDK. No other code in the SDK can be executed before building these per signal singletons.

So, by definition, once these singletons are executed, it is guaranteed that every other class used in the SDK implementation will see an already initialized global log handler.

There is not need, to fix this bug, to add log statements in every classes, even if another class uses a lazy singleton pattern.

Copy link
Member

@marcalff marcalff left a comment

Choose a reason for hiding this comment

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

LGTM, thanks for the investigation and fix.

@@ -26,6 +27,7 @@ LoggerProvider::LoggerProvider(std::unique_ptr<LogRecordProcessor> &&processor,
std::vector<std::unique_ptr<LogRecordProcessor>> processors;
processors.emplace_back(std::move(processor));
context_ = std::make_shared<sdk::logs::LoggerContext>(std::move(processors), std::move(resource));
OTEL_INTERNAL_LOG_DEBUG("[LoggerProvider] LoggerProvider created.");
Copy link
Member

Choose a reason for hiding this comment

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

How about other ctors? Didn't add the log there because they are not used by lazy singleton pattern? Probably add the log for consistency as the log message is provider instance created.

The per signal singletons are the entry points to the SDK. No other code in the SDK can be executed before building these per signal singletons.

So, by definition, once these singletons are executed, it is guaranteed that every other class used in the SDK implementation will see an already initialized global log handler.

There is not need, to fix this bug, to add log statements in every classes, even if another class uses a lazy singleton pattern.

@johanpel
Copy link
Contributor

Thanks @lalitb for the fix!

yxue pushed a commit to yxue/opentelemetry-cpp that referenced this pull request Dec 5, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Segfault when MetricProvider tries to log to already destructed global log handler at exit
5 participants