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

sdk/log: Add BenchmarkLoggerProviderLoggerSame #5599

Closed
wants to merge 2 commits into from

Conversation

pellared
Copy link
Member

@pellared pellared commented Jul 10, 2024

What

Benchmark that demonstrates the performance of reacquiring the same logger.

goos: linux
goarch: amd64
pkg: go.opentelemetry.io/otel/sdk/log
cpu: Intel(R) Core(TM) i9-10885H CPU @ 2.40GHz
BenchmarkLoggerProviderLoggerSame-16    	13867015	        92.33 ns/op	      24 B/op	       1 allocs/op

Why

I want to add this benchmark as I want to showcase that passing an option causes a heap allocation. In order to not have this heap allocation the caller would need to create a cache which would increase the memory footprint.

Some bridge implementations (e.g. for zap; see here) would have to get a logger for each log record. I prefer if bridges could directly call logger.Logger("name", LoggerConfig{ InstrumentationVersion: "v1.2.3" } that would not cause a heap allocation instead of e.g. caching passed options (or loggers). Caching on the bridge side will increase the memory overhead and the complexity of the bridge implementation. It makes it also easier to use the Bridge API in an non-efficient way. While (I think) I know how to handle the problem in otelzap becasue the zapcore.Entry only has a "logger name" the problem would be if logging library has e.g. a "version" in its log entry. Therefore, I would feel safer if we would not use options as we are never sure if these statements from design doc are good:

The performance of acquiring a logger is not as critical as the performance of emitting a log record.
[...]
The bridge implementation should reuse loggers whenever possible.

#5367 looks to be a more performance-robust API. The Bridge API is intended to be used to implement bridges. Applications should not use it directly. Therefore, I think that we can have a different design from Trace and Metrics API. We already have a different design for Processor and "Record" for performance reasons.

Remarks

Even if we do not decide to go for #5367, I think this benchmark is useful to demonstrate to performance of reacquiring the logger when options are created directly in the invocation.

Copy link

codecov bot commented Jul 10, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 84.5%. Comparing base (f2bc57b) to head (5243f76).

Additional details and impacted files

Impacted file tree graph

@@           Coverage Diff           @@
##            main   #5599     +/-   ##
=======================================
- Coverage   84.5%   84.5%   -0.1%     
=======================================
  Files        271     271             
  Lines      22427   22427             
=======================================
- Hits       18970   18969      -1     
- Misses      3124    3125      +1     
  Partials     333     333             

see 1 file with indirect coverage changes

@pellared pellared added pkg:SDK Related to an SDK package area:logs Part of OpenTelemetry logs Skip Changelog PRs that do not require a CHANGELOG.md entry labels Jul 10, 2024
@pellared pellared self-assigned this Jul 10, 2024
Copy link
Member

@dmathieu dmathieu left a comment

Choose a reason for hiding this comment

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

Approving the benchmark per-se, will leave another comment as well.

@dmathieu
Copy link
Member

If we provide p.Logger(name, log.LoggerConfig{}), won't the bridge still have to cache the config (or recreate it every time, and create an allocation)?

Then, what would be the difference between:

p.LoggerFromConfig(name, cachedConfig)

Versus:

p.Logger(name, cachedListOfOptions...)

In both cases, the bridge has to cache a config/list of options.

@pellared
Copy link
Member Author

pellared commented Jul 10, 2024

Config passed by value will be allocated on stack which is cheap - there would be no need to cache the config. I can make a draft PR once the benchmark is merged.


var logger log.Logger
for i := 0; i < b.N; i++ {
logger = p.Logger("test", log.WithInstrumentationVersion("v1.2.3"))
Copy link
Contributor

Choose a reason for hiding this comment

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

Similar to our metric benchmarks, this passed option should be allocated outside of the evaluation loop. Otherwise, we are measuring the inefficient misuse of the API.

Copy link
Member Author

@pellared pellared Jul 10, 2024

Choose a reason for hiding this comment

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

Otherwise, we are measuring the inefficient misuse of the API.

This is the whole point of the benchmark is to show that such usage introduces a heap allocation. I find it is too easy to use the API in an inefficient way,

I think that it would be better if the user would not need to preallocate instrumentation version in order not introduce a heap allocation.

It would be better if "strightforward" usage (like inlining options) would not introduce performance overhead. I prefer to have an API which makes writing inefficient code harder. At the same time the most straightforward usage should be performant.

Copy link
Member Author

@pellared pellared Jul 10, 2024

Choose a reason for hiding this comment

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

Maybe I should add a comment like: "Showcase that not pre-allocating the options slice causes a heap allocation introduced by the compiler"?

Copy link
Contributor

Choose a reason for hiding this comment

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

If that is the case, then this seems like a re-hash of the already concluded extensive conversation about how we handle configuration:

Additionally, since we have already discussed this specific detail for the metric signal12 extensively, unless there are new developments, I would prefer to not have the same discussion again. Especially since there is are now 2 stable signals that have set our precedence and a documented policy.

Footnotes

  1. https://github.com/open-telemetry/opentelemetry-go/pull/3971#discussion_r1163272609

  2. topic of discussion in the April 13 2023 SIG meeting: https://docs.google.com/document/d/1E5e7Ld0NuU1iVvf-42tOBpu2VBBLYnh73GJuITGJTTU/edit#heading=h.9lojwomaurj2

This comment was marked as outdated.

Copy link
Member Author

@pellared pellared Jul 11, 2024

Choose a reason for hiding this comment

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

I am fine using options for things bootstrapping the SDK (creating exporters, providers, processors).

However, I find that using options on code that may be on the hot-path makes it too easy for the callers to write inefficient code. Take notice that log.Record already diverges from these guidelines. Maybe, we should work on an alternate guideline for handling configuration for code that we asses that may be on the hot-path (e.g. when recording a value)?

I also think that there is very low probability that we would need to create logger provider options on the fly in the bridges. If it would occur, we can always create a new API.

I am closing this PR and creating a new issue. Thank you for your insight.

sdk/log/provider_test.go Show resolved Hide resolved
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area:logs Part of OpenTelemetry logs pkg:SDK Related to an SDK package Skip Changelog PRs that do not require a CHANGELOG.md entry
Projects
Status: Done
Development

Successfully merging this pull request may close these issues.

3 participants