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

Define Enabled parameters for Logger #4203

Merged
merged 14 commits into from
Sep 20, 2024

Conversation

pellared
Copy link
Member

@pellared pellared commented Sep 9, 2024

Follows #4020

During 7/5/24 OTel Specification SIG meeting it was decided to move the discussion about parameters to a separate PR; a little cleaned up transcript:

We're essentially trying to foresee with this is like what arguments will need to be present, for this Enabled method. Is it just severity? Is it no arguments at all? Are we going to want to evolve the arguments over time. I don't have the answers to those questions.
I wonder if we can do something [...] just to progress this because there's kind of [...] chicken in the eggs problems here. [...] we want to get this merged. [...]
This API should be structured so that the arguments you pass to it are evolvable. [...] we can leave ourselves room to evolve it from multiple standpoints. There's explicit text that says that the arguments can change and it's experimental.
I think I'd feel good about it then, because then we could [...] get this valuable thing in now [...]
[...]
And maybe we open some sort of issue [...] as a prerequisite for stability, we should [...] more thoughtfully consider what arguments are required for this.

This is needed for stabilization of Logger.Enabled in the spec which is need for the stabilization of Go Logs API.

Related issue: open-telemetry/opentelemetry-go#5769

Implementation in Go: open-telemetry/opentelemetry-go#5791

Changes

Add a minimal (and maybe even sufficient?) set of parameters for Logger.Enabled:

Add guidelines/rules for the Enabled parameters.

@pellared pellared added spec:logs Related to the specification/logs directory area:api Cross language API specification issue enhancement New feature or request labels Sep 9, 2024
@pellared pellared self-assigned this Sep 9, 2024
@pellared pellared marked this pull request as ready for review September 9, 2024 09:04
@pellared pellared requested review from a team September 9, 2024 09:04
specification/logs/bridge-api.md Outdated Show resolved Hide resolved
specification/logs/bridge-api.md Outdated Show resolved Hide resolved
specification/logs/bridge-api.md Outdated Show resolved Hide resolved
specification/logs/bridge-api.md Outdated Show resolved Hide resolved
@pellared pellared requested review from lmolkova and MrAlias September 9, 2024 19:19
Copy link
Member

@jack-berg jack-berg left a comment

Choose a reason for hiding this comment

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

These parameters were included in the original PR, and we had a (long) conversation about their values here.

In a nutshell, my critique is that the SDK has to provide an implementation of this Logger#enabled method, but there is currently nothing in the SDK spec which would allow the Logger#enabled to do anything differently based on the context / severity arguments.

In its current form, this is half of a feature. SDKs will always response with Logger#enabled based on the logger's associated LoggerConfig.disabled, ignoring the severity / context arguments.

The disconnect appears to be based on the go implementation's concept of a FilterProcessor which is able to express whether or not it needs to process log records based on severity. This concept does not exist in the spec, and would need to for this concept to make sense.

@pellared
Copy link
Member Author

pellared commented Sep 10, 2024

In a nutshell, my critique is that the SDK has to provide an implementation of this Logger#enabled method, but there is currently nothing in the SDK spec which would allow the Logger#enabled to do anything differently based on the context / severity arguments.

Cannot this be proposed as a separate PR?

In Go SIG, we are indeed experimenting how to best model it on the SDK level. We have an experimental feature, but we would like to have some more feedback before we propose something to the specification.

I think we can separately work on specifying the API and how SDK is implementing the API.

In my opinion, designing and implementing the SDK implementation would be harder and more opinionated. Therefore, I think it would be better to separate those into distinct PRs.

I agree that not having any specification on the SDK level may be seen as a blocker of making it stable. On the other hand, there are already APIs which are not defined how the SDK should handle them like #4160.

Notice that this section is still in "Development".

specification/logs/bridge-api.md Outdated Show resolved Hide resolved
specification/logs/bridge-api.md Outdated Show resolved Hide resolved
@jack-berg
Copy link
Member

Cannot this be proposed as a separate PR?

I'm fine splitting this out in a way that allows iteration. But we need a way to not loose track of this - maybe a TODO in the spec and a new issue upon merging? Resolving this discrepancy between the API and SDK should be a blocker to stability.

@pellared pellared dismissed jack-berg’s stale review September 10, 2024 17:22

Tracking issues created

@trask
Copy link
Member

trask commented Sep 12, 2024

may also want to consider blocking stability on whether we want to include "event name" in the enabled parameters, e.g. see @lmolkova's open-telemetry/oteps#265 (comment)

@pellared
Copy link
Member Author

may also want to consider blocking stability on whether we want to include "event name" in the enabled parameters, e.g. see @lmolkova's open-telemetry/oteps#265 (comment)

If you want you can add it to #4208.

However, I do not think that it should block the stability of Enabled as:

  1. Adding a parameter would not be a breaking change
  2. I feel that there is no conclusion if we want to add an "event name" do the LogRecord model or if we just want to use an event.name log attribute for it. It may be better to add "attributes" to enabled parameters. I think we would rather use just an attribute for that. See Event basics oteps#265 (comment)

@reyang
Copy link
Member

reyang commented Sep 12, 2024

  1. Adding a parameter would not be a breaking change

💯

  1. I feel that there is no conclusion if we want to add an "event name" do the LogRecord model or if we just want to use an event.name log attribute for it. It may be better to add "attributes" to enabled parameters. I think we would rather use just an attribute for that. See Event basics oteps#265 (comment)

There might be more to consider (definitely not for this PR):

  1. Comparing strings could be very inefficient, many systems use integers (e.g. Event Id = 1001) in combination with user-friendly names.
  2. For platforms with very limited resource or mission critical software (e.g. IoT device, kernel drivers), folks might want to just emit the integer, then enrich the data in the pipeline/backend using the integer -> string name mapping.

pellared added a commit to open-telemetry/opentelemetry-go that referenced this pull request Sep 13, 2024
Fixes #5769

Related spec PR:
open-telemetry/opentelemetry-specification#4203

Remark: A follow-up in contrib is required and afterwards here to fix
the `example/dice`.

Benchstat results for `sdk/log` (`log` has no benchmarks related to
Enabled):

```
goos: linux
goarch: amd64
pkg: go.opentelemetry.io/otel/sdk/log
cpu: Intel(R) Core(TM) i9-10885H CPU @ 2.40GHz
                                  │    old.txt    │               new.txt                │
                                  │    sec/op     │    sec/op     vs base                │
BatchProcessorOnEmit-16              398.8n ± 10%   395.6n ± 12%        ~ (p=0.971 n=10)
Processor/Simple-16                  882.2n ±  8%   869.8n ±  9%        ~ (p=0.811 n=10)
Processor/Batch-16                   1.478µ ±  3%   1.485µ ±  5%        ~ (p=0.646 n=10)
Processor/SetTimestampSimple-16      847.8n ±  1%   844.6n ±  3%        ~ (p=0.247 n=10)
Processor/SetTimestampBatch-16       1.480µ ±  3%   1.473µ ±  4%        ~ (p=0.700 n=10)
Processor/AddAttributesSimple-16     930.0n ±  1%   933.8n ±  1%        ~ (p=0.172 n=10)
Processor/AddAttributesBatch-16      1.624µ ±  2%   1.639µ ±  2%        ~ (p=0.839 n=10)
Processor/SetAttributesSimple-16     903.4n ±  1%   895.1n ±  1%        ~ (p=0.190 n=10)
Processor/SetAttributesBatch-16      1.554µ ±  4%   1.529µ ±  3%        ~ (p=0.159 n=10)
LoggerNewRecord/5_attributes-16      346.0n ±  2%   343.3n ±  2%        ~ (p=0.448 n=10)
LoggerNewRecord/10_attributes-16     1.608µ ±  6%   1.503µ ±  2%   -6.53% (p=0.007 n=10)
LoggerEnabled-16                    34.305n ±  8%   6.706n ±  1%  -80.45% (p=0.000 n=10)
LoggerProviderLogger-16              636.9n ± 10%   605.8n ±  3%        ~ (p=0.105 n=10)
WalkAttributes/1_attributes-16       5.363n ±  3%   4.540n ± 14%  -15.34% (p=0.002 n=10)
WalkAttributes/10_attributes-16      5.436n ±  7%   4.461n ±  2%  -17.95% (p=0.000 n=10)
WalkAttributes/100_attributes-16     5.126n ±  9%   4.465n ±  1%  -12.90% (p=0.000 n=10)
WalkAttributes/1000_attributes-16    5.316n ±  9%   4.502n ±  5%  -15.32% (p=0.002 n=10)
SetAddAttributes/SetAttributes-16    220.5n ± 18%   192.6n ± 11%  -12.67% (p=0.007 n=10)
SetAddAttributes/AddAttributes-16    165.3n ± 21%   127.3n ± 22%  -22.96% (p=0.011 n=10)
SimpleProcessorOnEmit-16             2.159n ±  9%   2.167n ±  9%        ~ (p=0.739 n=10)
geomean                              178.3n         154.5n        -13.31%

                        │    old.txt    │             new.txt             │
                        │      B/s      │      B/s       vs base          │
BatchProcessorOnEmit-16   76.52Mi ± 11%   77.14Mi ± 14%  ~ (p=0.971 n=10)

                                  │    old.txt     │                new.txt                │
                                  │      B/op      │     B/op      vs base                 │
BatchProcessorOnEmit-16               0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/Simple-16                   417.0 ± 0%       417.0 ± 0%       ~ (p=1.000 n=10) ¹
Processor/Batch-16                  1.093Ki ± 1%     1.088Ki ± 1%       ~ (p=0.254 n=10)
Processor/SetTimestampSimple-16       417.0 ± 0%       417.0 ± 0%       ~ (p=1.000 n=10) ¹
Processor/SetTimestampBatch-16      1.095Ki ± 1%     1.084Ki ± 2%       ~ (p=0.361 n=10)
Processor/AddAttributesSimple-16      417.0 ± 0%       417.0 ± 0%       ~ (p=1.000 n=10) ¹
Processor/AddAttributesBatch-16     1.085Ki ± 1%     1.086Ki ± 1%       ~ (p=1.000 n=10)
Processor/SetAttributesSimple-16      465.0 ± 0%       465.0 ± 0%       ~ (p=1.000 n=10) ¹
Processor/SetAttributesBatch-16     1.129Ki ± 1%     1.125Ki ± 1%       ~ (p=0.084 n=10)
LoggerNewRecord/5_attributes-16       0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
LoggerNewRecord/10_attributes-16      610.0 ± 0%       610.0 ± 0%       ~ (p=1.000 n=10) ¹
LoggerEnabled-16                      0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
LoggerProviderLogger-16               359.0 ± 6%       346.0 ± 3%       ~ (p=0.117 n=10)
WalkAttributes/1_attributes-16        0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/10_attributes-16       0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/100_attributes-16      0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/1000_attributes-16     0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
SetAddAttributes/SetAttributes-16     48.00 ± 0%       48.00 ± 0%       ~ (p=1.000 n=10) ¹
SetAddAttributes/AddAttributes-16     0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
SimpleProcessorOnEmit-16              0.000 ± 0%       0.000 ± 0%       ~ (p=1.000 n=10) ¹
geomean                                          ²                 -0.27%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean

                                  │   old.txt    │               new.txt               │
                                  │  allocs/op   │ allocs/op   vs base                 │
BatchProcessorOnEmit-16             0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/Simple-16                 1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/Batch-16                  1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/SetTimestampSimple-16     1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/SetTimestampBatch-16      1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/AddAttributesSimple-16    1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/AddAttributesBatch-16     1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/SetAttributesSimple-16    2.000 ± 0%     2.000 ± 0%       ~ (p=1.000 n=10) ¹
Processor/SetAttributesBatch-16     2.000 ± 0%     2.000 ± 0%       ~ (p=1.000 n=10) ¹
LoggerNewRecord/5_attributes-16     0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
LoggerNewRecord/10_attributes-16    4.000 ± 0%     4.000 ± 0%       ~ (p=1.000 n=10) ¹
LoggerEnabled-16                    0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
LoggerProviderLogger-16             1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/1_attributes-16      0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/10_attributes-16     0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/100_attributes-16    0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
WalkAttributes/1000_attributes-16   0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
SetAddAttributes/SetAttributes-16   1.000 ± 0%     1.000 ± 0%       ~ (p=1.000 n=10) ¹
SetAddAttributes/AddAttributes-16   0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
SimpleProcessorOnEmit-16            0.000 ± 0%     0.000 ± 0%       ~ (p=1.000 n=10) ¹
geomean                                        ²               +0.00%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean
```
@pellared
Copy link
Member Author

pellared commented Sep 16, 2024

Here (Proposal A) is an idea how the SDK can implement Logger.Enabled.

@pellared
Copy link
Member Author

pellared commented Sep 17, 2024

Here (Proposal B) is a second (I think better) idea how the SDK can implement filtering which will affect not only Logger.Enabled but also Logger.Emit. It is more like sampling in tracing SDK.

@pellared pellared requested review from a team as code owners September 19, 2024 04:57
Comment on lines +149 to +156
Additional optional parameters can be added in the future, therefore,
the API MUST be structured in a way for these parameters to be added.

It SHOULD be possible to distinguish between an unspecified parameter value from
a parameter value set explicitly to a valid default value of given type
(e.g. distinguish unspecified attributes for empty attributes). The exception
from this rule is when the default value of given type is not seen as a valid
value like 0 for [Severity Number](./data-model.md#field-severitynumber).
Copy link
Member Author

@pellared pellared Sep 20, 2024

Choose a reason for hiding this comment

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

Suggested change
Additional optional parameters can be added in the future, therefore,
the API MUST be structured in a way for these parameters to be added.
It SHOULD be possible to distinguish between an unspecified parameter value from
a parameter value set explicitly to a valid default value of given type
(e.g. distinguish unspecified attributes for empty attributes). The exception
from this rule is when the default value of given type is not seen as a valid
value like 0 for [Severity Number](./data-model.md#field-severitynumber).

By @jack-berg in #4207 (comment):

I'm suspicious of the idea of introducing the concept of an expandable set of EnabledParameters, since requiring users to create a new struct / object to check if code should proceed to emitting a log seems non-optimal from a performance and ergonomics standpoint. I understand the desire to want to retain flexibility to evolve the API, but I think getting the arguments right in the initial stable version and not trying to retain the ability to evolve is likely to produce the most ergonomic API.

I think that in many languages expandable set of parameters for Logger.Enabled with acceptable performance and ergonomics standpoint can be achieved by using optional function/method arguments. But for Go you are correct, having Logger.Enabled to accept only context and severity would make the API more ergonomic.

I am worried that is may be hard to get the arguments right in the initial version. For instance, should we allow filtering based on attributes or body? Do we want to close the doors for such possibility? On the other hand, from my experience having only context and severity would cover 99% of use cases and having a better ergonomics and easier design is also desirable.

Copy link
Member

Choose a reason for hiding this comment

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

On the other hand, from my experience having only context and severity would cover 99% of use cases

Agree on this. Most logging frameworks I am familiar with provide IsEnabled/equivalent by using minimal arguments, and in particular, those arguments that are known easily (static in some languages like Rust). The usual goal of IsEnabled is optimize performance, so minimal arguments meets the goal here.
Examples:
.NET ILogger allows filtering based on Severity, Scope only.
Rust's tracing (logging solution!), only allows filtering based on Severity,Scope,Name (event name)

For filtering based on attributes/body (or anything that is dynamic in nature) - these are typically done not for Perf savings, but for saving backend storage costs. These are better handled by LogRecordProcessor (in-proc) or Collector (out-of-proc).

Copy link
Member Author

Choose a reason for hiding this comment

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

only allows filtering based on Severity,Scope,Name (event name)

The scope will be known by the SDK - no need to add it to Enabled as the parameter.

Question if we would need event name as a parameter. @cijothomas do you know if this is frequently used and what are the use cases when it is used? I think a prerequisite for it would be to to add it as a field to LogRecord (it could be defined in the same way as Body and named ID or Name).

Copy link
Member

@cijothomas cijothomas Sep 20, 2024

Choose a reason for hiding this comment

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

The scope will be known by the SDK - no need to add it to Enabled as the parameter.

Oh that is correct!

Copy link
Member

Choose a reason for hiding this comment

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

Regd. EventName being used for EnabledCheck:

  1. It is very important (actually the EventId, the numerical, machine friendly version of EventName that is most important to do ultra fast checks!) for scenarios we are working on in OTel Rust, C++. I don't know if it is something every language/implementation cares about. Given spec does not prohibit an implementation from allowing more parameters, I am totally okay if spec does not mention it, as OTel C++/Rust can offer this as extras.
  2. From the Event Oteps, there were mention of scenarios where Loggers can filter based on EventName, route things to different places based on EventName etc. It'd be good to wait to see the progress on Events before we can really say if EventName is a important parameter for the Enabled check.

Copy link
Member

Choose a reason for hiding this comment

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

Not a blocker for this PR

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area:api Cross language API specification issue enhancement New feature or request spec:logs Related to the specification/logs directory
Projects
Status: Done
Development

Successfully merging this pull request may close these issues.

8 participants