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.

Sign up for GitHub

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

logs: Add durable identifier log record attributes #1339

Closed
wants to merge 3 commits into from
Closed

logs: Add durable identifier log record attributes #1339

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
1f3c200
Add durable identifier log record attributes.
CodeBlanch Aug 16, 2024
74d9e31
Code review.
CodeBlanch Aug 19, 2024
da3e4e8
Code review and lint fixes.
CodeBlanch Aug 19, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
77 changes: 68 additions & 9 deletions docs/attributes-registry/log.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,12 +40,71 @@ Attributes for a file to which log was emitted.

This document defines the generic attributes that may be used in any Log Record.

| Attribute | Type | Description | Examples | Stability |
| --------------------- | ------ | ------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------- | ---------------------------------------------------------------- |
| `log.record.original` | string | The complete orignal Log Record. [1] | `77 <86>1 2015-08-06T21:58:59.694Z 192.168.2.133 inactive - - - Something happened`; `[INFO] 8/3/24 12:34:56 Something happened` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
| `log.record.uid` | string | A unique identifier for the Log Record. [2] | `01ARZ3NDEKTSV4RRFFQ69G5FAV` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |

**[1]:** This value MAY be added when processing a Log Record which was originally transmitted as a string or equivalent data type AND the Body field of the Log Record does not contain the same value. (e.g. a syslog or a log record read from a file.)

**[2]:** If an id is provided, other log records with the same id will be considered duplicates and can be removed safely. This means, that two distinguishable log records MUST have different values.
The id MAY be an [Universally Unique Lexicographically Sortable Identifier (ULID)](https://github.com/ulid/spec), but other identifiers (e.g. UUID) may be used as needed.
| Attribute | Type | Description | Examples | Stability |
| --------------------- | ------ | -------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------- | ---------------------------------------------------------------- |
| `log.record.id` | int | A durable identifier for the Log Record. [1] | `1`; `10018` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
Copy link
Member

Choose a reason for hiding this comment

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

Are there any uniqueness requirements/guarantees for the id? Do we expect it to be globally unique? Unique within some limited scope? Are there any mechanisms for preventing id conflicts?

We also have code.* attributes that can point to a particular place in the code that emits the log record that can serve as sort of durable identifier (e.g. filename+function+line). What's the interplay (if any) between these and the newly proposed attribute?

Copy link
Member

Choose a reason for hiding this comment

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

filename/function/line etc. is not really durable, as it can change just with code refactoring!

Here is an example of EventId/Name: https://learn.microsoft.com/en-us/dotnet/core/extensions/logging?tabs=command-line#log-event-id

Copy link
Member

Choose a reason for hiding this comment

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

OK, makes sense regarding code references.

I think we still need clarity around uniqueness, conflicts, etc.

Copy link
Member

Choose a reason for hiding this comment

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

Resolving this conversation and we can continue in #1339 (comment)

| `log.record.name` | string | A durable name for the Log Record. [2] | `RequestProcessed`; `InvalidResponse` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
Copy link
Member

Choose a reason for hiding this comment

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

How are id and name related? Is name supposed to be the human-readable equivalent of id? Can different id-ed logrecords have the same name?

Copy link
Member

Choose a reason for hiding this comment

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

Is name supposed to be the human-readable equivalent of id

Yes.

Can different id-ed logrecords have the same name?

Not in well behaved application.

Copy link
Contributor

@lmolkova lmolkova Aug 23, 2024 •
edited
Loading

Choose a reason for hiding this comment

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

Based on today's discussion in the Event SIG, I believe we should use event.name for the durable log name.

The gist of the discussion:

If logging API allows to define event name (like .NET, C++ and maybe Rust do), e.g.

logger.LogInformation(new EventId(id: 42, name: "com.foo.my-event-name"), "something important")

then the corresponding name should be recorded as an event.name.

It's a user responsibility to provide a unique name, there is nothing we can do to enforce it if users call Event API directly.

So if user does logger.LogInformation(new EventId(42, "foo"), "something important") the best that logging bridge can do is to use the name that user provided and set event.name = foo.

I wonder if other participants share the same understanding @CodeBlanch @MSNev @trask @breedx-splk

Copy link
Member

@tigrannajaryan tigrannajaryan Aug 23, 2024 •
edited
Loading

Choose a reason for hiding this comment

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

Related to this, early versions of Log data model had a Name field defined as:

Short event identifier that does not contain varying parts. Name describes what happened (e.g. "ProcessStarted"). Recommended to be no longer than 50 characters. Not guaranteed to be unique in any way. Typically used for filtering and grouping purposes in backends. This field is optional.

This seems pretty close to what the proposed log.record.name is and also to existing event.name. It almost feels like we should have kept the Name field on LogRecord. I commented here that I think we need consider adding it back and then it would replace event.name and the proposed log.record.name.

Copy link
Contributor

Choose a reason for hiding this comment

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

Based on today's discussion in the Event SIG, I believe we should use event.name for the durable log name.

The gist of the discussion:

If logging API allows to define event name (like .NET, C++ and maybe Rust do), e.g.

logger.LogInformation(new EventId(id: 42, name: "com.foo.my-event-name"), "something important")

then the corresponding name should be recorded as an event.name.

It's a user responsibility to provide a unique name, there is nothing we can do to enforce it if users call Event API directly.

So if user does logger.LogInformation(new EventId(42, "foo"), "something important") the best that logging bridge can do is to use the name that user provided and set event.name = foo.

I wonder if other participants share the same understanding @CodeBlanch @MSNev @trask @breedx-splk

This is effectively what we talked about, however, as mentioned in the call my point of view (and recommendation) is still that otel "should" define that for this scenario there is a generic prefix that is prepended to event.name to ensure that these types of events cannot directly clash with any other OTel defined event.

During the meeting I proposed log.* but perhaps better options would be either app.*, user.* or custom.* so that it is explicitly called for backend processors of "known" event names that this is a custom event and therefore should be treated as such, as opposed to requiring them to enforce (more explicit) validity checks on any possible "known" events than necessary).

This should also NOT preclude the ability of languages reusing their existing logging mechanism's to "generate" true valid OTel defined events (without any prefix automatically added). Which could be done (potentially) by the introduction of some other explicitly named "element" (class, provider, property, attribute etc)

Copy link
Member

Choose a reason for hiding this comment

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

It almost feels like we should have kept the Name field on LogRecord. I open-telemetry/opentelemetry-specification#3406 (comment) that I think we need consider adding it back and then it would replace event.name and the proposed log.record.name.

+1 . Irrespective of that, in implementations, (.NET, Rust), we store name as a top-level field in LogRecord, and while exporting, its sent via attributes.

Copy link
Member

Choose a reason for hiding this comment

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

I think that changing or eliminating event.name would be a step backwards at this point.

That is not part of the proposal, right?

Just put the readable id into the event.name attribute and put the numeric id into a long attribute named whatever non-semconv thing you want.

This is not just a .NET specific thing, else we could have just used attribute named "dotnet.ilogger.eventid.id"/similar. The goal is to get something language neutral. .NET's ILogger was used as an example.

OTel C++ has the exact same need.
OTel Rust don't yet have the numerical identifier (it just has the human readable name part), but we are trying to get it added as well.

Copy link
Contributor

Choose a reason for hiding this comment

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

I agree, it seems we have 3 different discussions here

  1. use event.name vs introduce new log.record.name
  2. do we need first-class data model Name property on logs
  3. how to capture id (that appears in several languages and also in windows event log).

Maybe we can focus on the p1 in this thread

Copy link
Contributor

Choose a reason for hiding this comment

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

Yes back on topic! log.record.name!

My suggestion is that we separate log.record.name and log.record.id. The ID attribute is clear cut and valuable, not to mention a big deal. My request would be to please reduce this PR so that it only contains the ID attribute. That can go ahead and be approved based on its own merits.

If log.record.name really is incompatible with our definition of event.name, please make a separate PR for log.record.name that clearly presents which issues the additional name field would address. ✌️

on the name field thing

Philosophically I agree that Name should be a field on LogRecord. That would match the way we handle it on Span. But in this particular case, I believe that the Name field actually complicates things.

This is the problem: we want to support the use case where 3rd party loggers can create events on their own. Those loggers have no concept of a Name field, so they would have to use the event.name attribute pattern. Which means that there would have to be code in various places that scans for the event.name attribute, and then tries to delete that attribute and move the value over to the Name field.

Because support for 3rd party loggers is critical, there is no escaping the existence of the event.name attribute in many parts of our logging pipeline. Which means that the choice is not between "do you want to only have an event.name attribute?" and "do you want to only have an Name field?", it is actually between "do you want to only have an event.name attribute?" or "do you want to have both an event.name attribute plus a Name field you have to check?"

Long story short: It appears to be the case that a lot of double checking and confusion could be avoided if we just stick with the attribute event.name. Solving problems by doing nothing, this is The Way. :)

Copy link
Member

Choose a reason for hiding this comment

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

Based on these discussions/feedback, this is my understanding:

  1. There is general agreement that there is no need of introducing log.record.name as it is same as the event.name. That makes every log done using .NET's ILogger with EventName (eg: logger.Log(new EventId(10, "LoginFailed"), body, attributes);) an OTel Event, as it is a LogRecord with an attribute "event.name". No need of spec/semantic convention changes, OTel .NET can fix its implementation to store EventName as "event.name".

  2. The numerical version of the "event.name", could be named "event.id", call out that "event.id" and "event.name" should have 1:1 relation in a well behaved app. This can be a separate PR.

example:

var logger = GetLogger("company.product.service.module");
logger.Log(new EventId(10, "LoginFailed"), body, attributes);

The above will produce a LogRecord with scope name set to "company.product.service.module", and attribute containing "event.name" = "LoginFailed", and "event.id" = 10 (along with body and other attributes)

Is this everyone's understanding as well?

| `log.record.original` | string | The complete orignal Log Record. [3] | `77 <86>1 2015-08-06T21:58:59.694Z 192.168.2.133 inactive - - - Something happened`; `[INFO] 8/3/24 12:34:56 Something happened` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
| `log.record.uid` | string | A unique identifier for the Log Record. [4] | `01ARZ3NDEKTSV4RRFFQ69G5FAV` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |

**[1]:** This value MAY be added when processing a Log Record which has the
concept of a durable identifier.

A durable identifier is a unique value assigned to a well-known Log
Record inside a given instrumentation scope. A durable identifier
SHOULD be traceable back to a specific piece of code where the log is
defined. Durable identifiers MAY be used to safely and efficiently
filter Log Records which produce high volume and yield low value
(spammy logs).

Consider this pseudo-code example:
Copy link
Member

Choose a reason for hiding this comment

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

this is actually csharp code, did you intend to switch to pseudo code?
logger.log(eventid, eventname, rest-of-logging-things-like-body-attributes-severity-etc)


```csharp
internal static partial class LoggerExtensions
{
[LogMessage(
1, // Durable identifier
"FoodPriceChanged", // Durable name
LogLevel.Information, // Severity
"Food `{name}` price changed to `{price}`.")] // Body
public static partial void LogFoodPriceChanged(
this ILogger<MyLogic> logger, // Instrumentation scope
string name, // Attribute
double price); // Attribute

[LogMessage(
2, // Durable identifier
"FoodRecallNotice", // Durable name
LogLevel.Critical, // Severity
"A `{productType}` recall notice was published for `{brandName} {productDescription}` produced by `{companyName}` ({recallReasonDescription}).")] // Body
public static partial void LogFoodRecallNotice(
this ILogger<MyLogic> logger, // Instrumentation scope
string brandName, // Attribute
string productDescription, // Attribute
string productType, // Attribute
string recallReasonDescription, // Attribute
string companyName); // Attribute
}
```

Two log helpers are defined inside the `MyLogic` instrumentation
scope: `LogFoodPriceChanged` (with the durable identifier `1`) and
`LogFoodRecallNotice` (with the durable identifier `2`). All Log
Records emitted using `LogFoodPriceChanged` will have
`log.record.id=1` and all Log Records emitted using
`LogFoodRecallNotice` will have `log.record.id=2`.

**[2]:** This value MAY be added when processing a Log Record which has the
concept of a durable name.

A durable name is the human readable version of the durable
identifier. A durable name is a unique value assigned to a well-known
Log Record inside a given instrumentation scope. In the above example
all Log Records emitted using `LogFoodPriceChanged` will have
`log.record.name=FoodPriceChanged` and all Log Records emitted using
`LogFoodRecallNotice` will have `log.record.name=FoodRecallNotice`.

**[3]:** This value MAY be added when processing a Log Record which was originally transmitted as a string or equivalent data type AND the Body field of the Log Record does not contain the same value. (e.g. a syslog or a log record read from a file.)

**[4]:** If an uid is provided, other log records with the same uid will be considered duplicates and can be removed safely. This means, that two distinguishable log records MUST have different values.
The uid MAY be an [Universally Unique Lexicographically Sortable Identifier (ULID)](https://github.com/ulid/spec), but other identifiers (e.g. UUID) may be used as needed.
73 changes: 66 additions & 7 deletions docs/general/logs.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -44,13 +44,72 @@ These attributes may be used for identifying a Log Record.

| Attribute | Type | Description | Examples | [Requirement Level](https://opentelemetry.io/docs/specs/semconv/general/attribute-requirement-level/) | Stability |
|---|---|---|---|---|---|
| [`log.record.original`](/docs/attributes-registry/log.md) | string | The complete orignal Log Record. [1] | `77 <86>1 2015-08-06T21:58:59.694Z 192.168.2.133 inactive - - - Something happened`; `[INFO] 8/3/24 12:34:56 Something happened` | `Opt-In` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
| [`log.record.uid`](/docs/attributes-registry/log.md) | string | A unique identifier for the Log Record. [2] | `01ARZ3NDEKTSV4RRFFQ69G5FAV` | `Opt-In` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |

**[1]:** This value MAY be added when processing a Log Record which was originally transmitted as a string or equivalent data type AND the Body field of the Log Record does not contain the same value. (e.g. a syslog or a log record read from a file.)

**[2]:** If an id is provided, other log records with the same id will be considered duplicates and can be removed safely. This means, that two distinguishable log records MUST have different values.
The id MAY be an [Universally Unique Lexicographically Sortable Identifier (ULID)](https://github.com/ulid/spec), but other identifiers (e.g. UUID) may be used as needed.
| [`log.record.id`](/docs/attributes-registry/log.md) | int | A durable identifier for the Log Record. [1] | `1`; `10018` | `Recommended` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
| [`log.record.name`](/docs/attributes-registry/log.md) | string | A durable name for the Log Record. [2] | `RequestProcessed`; `InvalidResponse` | `Recommended` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
| [`log.record.original`](/docs/attributes-registry/log.md) | string | The complete orignal Log Record. [3] | `77 <86>1 2015-08-06T21:58:59.694Z 192.168.2.133 inactive - - - Something happened`; `[INFO] 8/3/24 12:34:56 Something happened` | `Opt-In` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |
| [`log.record.uid`](/docs/attributes-registry/log.md) | string | A unique identifier for the Log Record. [4] | `01ARZ3NDEKTSV4RRFFQ69G5FAV` | `Opt-In` | ![Experimental](https://img.shields.io/badge/-experimental-blue) |

**[1]:** This value MAY be added when processing a Log Record which has the
concept of a durable identifier.

A durable identifier is a unique value assigned to a well-known Log
Record inside a given instrumentation scope. A durable identifier
SHOULD be traceable back to a specific piece of code where the log is
defined. Durable identifiers MAY be used to safely and efficiently
filter Log Records which produce high volume and yield low value
(spammy logs).

Consider this pseudo-code example:

```csharp
internal static partial class LoggerExtensions
{
[LogMessage(
1, // Durable identifier
"FoodPriceChanged", // Durable name
LogLevel.Information, // Severity
"Food `{name}` price changed to `{price}`.")] // Body
public static partial void LogFoodPriceChanged(
this ILogger<MyLogic> logger, // Instrumentation scope
string name, // Attribute
double price); // Attribute

[LogMessage(
2, // Durable identifier
"FoodRecallNotice", // Durable name
LogLevel.Critical, // Severity
"A `{productType}` recall notice was published for `{brandName} {productDescription}` produced by `{companyName}` ({recallReasonDescription}).")] // Body
public static partial void LogFoodRecallNotice(
this ILogger<MyLogic> logger, // Instrumentation scope
string brandName, // Attribute
string productDescription, // Attribute
string productType, // Attribute
string recallReasonDescription, // Attribute
string companyName); // Attribute
}
```

Two log helpers are defined inside the `MyLogic` instrumentation
scope: `LogFoodPriceChanged` (with the durable identifier `1`) and
`LogFoodRecallNotice` (with the durable identifier `2`). All Log
Records emitted using `LogFoodPriceChanged` will have
`log.record.id=1` and all Log Records emitted using
`LogFoodRecallNotice` will have `log.record.id=2`.

**[2]:** This value MAY be added when processing a Log Record which has the
concept of a durable name.

A durable name is the human readable version of the durable
identifier. A durable name is a unique value assigned to a well-known
Log Record inside a given instrumentation scope. In the above example
all Log Records emitted using `LogFoodPriceChanged` will have
`log.record.name=FoodPriceChanged` and all Log Records emitted using
`LogFoodRecallNotice` will have `log.record.name=FoodRecallNotice`.

**[3]:** This value MAY be added when processing a Log Record which was originally transmitted as a string or equivalent data type AND the Body field of the Log Record does not contain the same value. (e.g. a syslog or a log record read from a file.)

**[4]:** If an uid is provided, other log records with the same uid will be considered duplicates and can be removed safely. This means, that two distinguishable log records MUST have different values.
The uid MAY be an [Universally Unique Lexicographically Sortable Identifier (ULID)](https://github.com/ulid/spec), but other identifiers (e.g. UUID) may be used as needed.



Expand Down
4 changes: 4 additions & 0 deletions model/logs/general.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,3 +8,7 @@ groups:
requirement_level: opt_in
- ref: log.record.original
requirement_level: opt_in
- ref: log.record.id
requirement_level: recommended
- ref: log.record.name
requirement_level: recommended
77 changes: 75 additions & 2 deletions model/registry/log.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -63,10 +63,10 @@ groups:
brief: >
A unique identifier for the Log Record.
note: >
If an id is provided, other log records with the same id will be considered duplicates and can be removed safely.
If an uid is provided, other log records with the same uid will be considered duplicates and can be removed safely.
This means, that two distinguishable log records MUST have different values.

The id MAY be an [Universally Unique Lexicographically Sortable Identifier (ULID)](https://github.com/ulid/spec),
The uid MAY be an [Universally Unique Lexicographically Sortable Identifier (ULID)](https://github.com/ulid/spec),
but other identifiers (e.g. UUID) may be used as needed.
examples: ["01ARZ3NDEKTSV4RRFFQ69G5FAV"]
- id: log.record.original
Expand All @@ -80,3 +80,76 @@ groups:
examples:
- "77 <86>1 2015-08-06T21:58:59.694Z 192.168.2.133 inactive - - - Something happened"
- "[INFO] 8/3/24 12:34:56 Something happened"
- id: log.record.id
type: int
stability: experimental
brief: >
A durable identifier for the Log Record.
note: |
This value MAY be added when processing a Log Record which has the
concept of a durable identifier.

A durable identifier is a unique value assigned to a well-known Log
Record inside a given instrumentation scope. A durable identifier
SHOULD be traceable back to a specific piece of code where the log is
defined. Durable identifiers MAY be used to safely and efficiently
filter Log Records which produce high volume and yield low value
(spammy logs).

Consider this pseudo-code example:

```csharp
internal static partial class LoggerExtensions
{
[LogMessage(
1, // Durable identifier
"FoodPriceChanged", // Durable name
LogLevel.Information, // Severity
"Food `{name}` price changed to `{price}`.")] // Body
public static partial void LogFoodPriceChanged(
this ILogger<MyLogic> logger, // Instrumentation scope
string name, // Attribute
double price); // Attribute

[LogMessage(
2, // Durable identifier
"FoodRecallNotice", // Durable name
LogLevel.Critical, // Severity
"A `{productType}` recall notice was published for `{brandName} {productDescription}` produced by `{companyName}` ({recallReasonDescription}).")] // Body
public static partial void LogFoodRecallNotice(
this ILogger<MyLogic> logger, // Instrumentation scope
string brandName, // Attribute
string productDescription, // Attribute
string productType, // Attribute
string recallReasonDescription, // Attribute
string companyName); // Attribute
}
```

Two log helpers are defined inside the `MyLogic` instrumentation
scope: `LogFoodPriceChanged` (with the durable identifier `1`) and
`LogFoodRecallNotice` (with the durable identifier `2`). All Log
Records emitted using `LogFoodPriceChanged` will have
`log.record.id=1` and all Log Records emitted using
`LogFoodRecallNotice` will have `log.record.id=2`.
examples:
- 1
- 10018
- id: log.record.name
type: string
stability: experimental
brief: >
A durable name for the Log Record.
note: |
This value MAY be added when processing a Log Record which has the
concept of a durable name.

A durable name is the human readable version of the durable
identifier. A durable name is a unique value assigned to a well-known
Log Record inside a given instrumentation scope. In the above example
all Log Records emitted using `LogFoodPriceChanged` will have
`log.record.name=FoodPriceChanged` and all Log Records emitted using
`LogFoodRecallNotice` will have `log.record.name=FoodRecallNotice`.
examples:
- "RequestProcessed"
- "InvalidResponse"
Loading