go/adbc:/drivers/flightsql convert slog messages to OTel trace spans and events

[birschick-bq]

What feature or improvement would you like to see?

Currently, the FlightSQL go driver has instrumented slog messages (DebugContext, InfoContext, etc.) to log diagnostic messages.

However, the slog messages are (currently) only routed to the stderr stream and are not persisted to the file system or available to OTel endpoints.

I suggest that we port the slog messages to OTel tracing spans (internal.StartSpan / internal.EndSpanWithError) and events (span.AddEvent / span.RecordError) so that the information can be persisted to the file system or available to OTel endpoints.

There are other alternatives,

• add an io.Writer implementation to the slog streaming implementation - for file system persistence.
• use the OTel logging bridge - for slog to OTel logging.

However, I'm assuming we are content to standardize on using OTel tracing.

[lidavidm]

Shouldn't slog be ported to OTel logging, and not tracing?

If we want span events etc. we should do that porting manually. I'm not sure that all logs belong as span events.

[birschick-bq]

@lidavidm Thanks for the feedback.

• Using the OTel bridge for slog would be convenient so we wouldn't have to port/rewrite any existing logging code. But I have a few concerns ...
  • We'll need to add support for the OTel logging environment variable like the exporter (OTEL_LOGS_EXPORTER) and level (OTEL_LOG_LEVEL)
  • Database/Connection options to set the exporter and level (and others for file-based exporter).
  • Endpoints or automated analysis of the data would now have to deal with two different data models.

Do you have a description of what information is more appropriate for logging than for tracing? Is it based on the "volume" of output? Or details?

Do you see that we might need to instrument two API calls for some information, one for logging and one for tracing?

[lidavidm]

Well, that's why I think

If we want span events etc. we should do that porting manually. I'm not sure that all logs belong as span events.

Perhaps our log calls should actually be part of spans. But I don't want to turn logs into spans just for the sake of it. I think a span should be associated with a request in some way, at least for drivers. I don't think something should be instrumented twice.

[birschick-bq]

@lidavidm

My guidelines for spans and converting logs to span events ...

• spans should be started (probably exclusively) from public API methods (ExecuteQuery, ExecuteUpdated, GetInfo, etc.)
• existing logging, if converted to tracing should
  • not duplicate recording duration that is already handled by the span
  • not duplicate recording errors that are already handled by the span helper (internal.EndSpanWithError()).
  • consider adding a attribute to the events to indicate whether the event is warning, informational or debug level of information.
  • only add events for repetitive tasks if part of a batch and not for either m columns or n rows.

[lidavidm]

That seems reasonable enough

[birschick-bq]

@lidavidm

I've got 3 PRs in the queue that try to address this issue:

1. feat(go/adbc): refactor logging instrumentation into OTel tracing - part 1/3 #4655
2. feat(go/adbc): refactor logging instrumentation into OTel tracing - part 2/3 #4659
3. feat(go/adbc): refactor logging instrumentation into OTel tracing - part 2/3 #4659