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 OTEL logging in HotRod example #4556

Merged
merged 12 commits into from Jul 2, 2023

Conversation

albertteoh
Copy link
Contributor

@albertteoh albertteoh commented Jul 1, 2023

Short description of the changes

  • A cleaned up version of OTEL span logging in HotRod example #4550.
  • It uses a single spanLogger for both OpenTracing and OpenTelemetry spans.
    • The logging works for both types spans because of this clever line of code where tracerWithHook is an OTEL bridge tracer, allowing span to be stored in the ctx the "OTEL-way", making the span discoverable as a legitimate OTEL span such that ok == true:
if span, ok := ctx.Value(currentSpanKey).(Span); ok { ... }

Testing

Ran locally to confirm logs appearing for both OpenTracing spans:

Screenshot 2023-07-01 at 8 12 16 pm

and OpenTelemetry spans:
Screenshot 2023-07-01 at 8 12 08 pm

@albertteoh albertteoh requested a review from a team as a code owner July 1, 2023 11:34
Signed-off-by: albertteoh <see.kwang.teoh@gmail.com>
examples/hotrod/pkg/log/spanlogger.go Show resolved Hide resolved
// - uint64 -> string
// - float32 -> float64
//
// See: https://github.com/open-telemetry/opentelemetry-go/blob/main/bridge/opentracing/bridge.go#L538
Copy link
Contributor Author

Choose a reason for hiding this comment

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

As the comment states, the mappings below are taken from the OTEL bridge to maintain consistency.

@codecov
Copy link

codecov bot commented Jul 1, 2023

Codecov Report

Patch and project coverage have no change.

Comparison is base (855b226) 97.03% compared to head (a31b067) 97.03%.

Additional details and impacted files
@@           Coverage Diff           @@
##             main    #4556   +/-   ##
=======================================
  Coverage   97.03%   97.03%           
=======================================
  Files         301      301           
  Lines       17837    17837           
=======================================
  Hits        17308    17308           
  Misses        424      424           
  Partials      105      105           
Flag Coverage Δ
unittests 97.03% <ø> (ø)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Do you have feedback about the report comment? Let us know in this issue.

// TODO rather than always converting the fields, we could wrap them into a lazy logger
fa := fieldAdapter(make([]log.Field, 0, 2+len(fields)))
fa = append(fa, log.String("event", msg))
fa = append(fa, log.String("level", level))
Copy link
Member

Choose a reason for hiding this comment

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

Level was used!

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Ha! Yes, you're right, my bad for this oversight and thanks for the callout. Added "level" as an attribute to the logs in: a31b067

Note that the MySQL spans are missing the log level:

Screenshot 2023-07-02 at 7 20 44 am

That's because LogFields is invoked directly from the active span here:

activeSpan.LogFields(
.

Is this something we should fix in this PR?

Copy link
Member

Choose a reason for hiding this comment

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

looks fine as is. Level is not meaningful in the span logs, the only reason to transfer it when converting real logs is to keep data fidelity.

)
}

func otLogFieldsToOTelAttrs(fields []zapcore.Field) []attribute.KeyValue {
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
func otLogFieldsToOTelAttrs(fields []zapcore.Field) []attribute.KeyValue {
func logFieldsToOTelAttrs(fields []zapcore.Field) []attribute.KeyValue {

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Renamed in: b1d21a1

}

type fieldAdapter []log.Field
func (e *bridgeFieldEncoder) AddBinary(key string, value []byte) {
e.pairs = append(e.pairs, otTagToOTelAttr(key, value))
Copy link
Member

Choose a reason for hiding this comment

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

Since we know the type here, why do we call into method that erases the type and has to match on it at runtime? We could call the right otel attribute constructor right here.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Just out of convenience, particularly for the "unsupported" types which fall back to the default case; although I like the fact that there's less indirection, so I've made direct calls in: b1d21a1.

Signed-off-by: albertteoh <see.kwang.teoh@gmail.com>
Signed-off-by: albertteoh <see.kwang.teoh@gmail.com>
@albertteoh albertteoh merged commit 050ba81 into jaegertracing:main Jul 2, 2023
31 checks passed
@albertteoh albertteoh deleted the fix-otel-logging-hotrod branch July 2, 2023 09:42
afzal442 pushed a commit to Cloud-Hacks/jaeger that referenced this pull request Jul 10, 2023
## Short description of the changes
- A cleaned up version of
jaegertracing#4550.
- It uses a single spanLogger for both OpenTracing and OpenTelemetry
spans.
- The logging works for both types spans because of [this clever line of
code](https://github.com/opentracing/opentracing-go/blob/master/gocontext.go#L14)
where `tracerWithHook` is an OTEL bridge tracer, allowing span to be
stored in the `ctx` the "OTEL-way", making the span discoverable as a
legitimate OTEL span such that `ok == true`:

```go
if span, ok := ctx.Value(currentSpanKey).(Span); ok { ... }
```

## Testing

Ran locally to confirm logs appearing for both OpenTracing spans:

![Screenshot 2023-07-01 at 8 12 16
pm](https://github.com/jaegertracing/jaeger/assets/26584478/572b037a-8fbb-43aa-abdf-6a8a2a137f89)

and OpenTelemetry spans:
![Screenshot 2023-07-01 at 8 12 08
pm](https://github.com/jaegertracing/jaeger/assets/26584478/681da3b3-8f07-4f85-b60e-8235592c89bd)

---------

Signed-off-by: albertteoh <see.kwang.teoh@gmail.com>
Signed-off-by: Afzal Ansari <afzal442@gmail.com>
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.

None yet

2 participants