Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
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
8 changes: 0 additions & 8 deletions options.go
Original file line number Diff line number Diff line change
Expand Up @@ -71,14 +71,6 @@ func WithTrimSQLInSpanName() Option {
})
}

// WithDisableAcquireTracer disables tracing for connection acquire events from
// the connection pool. By default, acquire tracing is enabled.
func WithDisableAcquireTracer() Option {
return optionFunc(func(cfg *tracerConfig) {
cfg.disableAcquireTracer = true
})
}

// SpanNameFunc is a function that can be used to generate a span name for a
// SQL. The function will be called with the SQL statement as a parameter.
type SpanNameFunc func(stmt string) string
Expand Down
126 changes: 20 additions & 106 deletions tracer.go
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,9 @@ const (
PGXOperationTypeKey = attribute.Key("pgx.operation.type")
// DBClientOperationErrorsKey represents the count of operation errors
DBClientOperationErrorsKey = attribute.Key("db.client.operation.errors")
// PrepareDurationKey records the wall-clock time of a prepared-statement
// round-trip, in milliseconds, as an attribute on the parent query span.
PrepareDurationKey = attribute.Key("pgx.prepare.duration")
)

type startTimeCtxKey struct{}
Expand Down Expand Up @@ -81,7 +84,6 @@ type Tracer struct {
logSQLStatement bool
logConnectionDetails bool
includeParams bool
disableAcquireTracer bool
}

type tracerConfig struct {
Expand All @@ -97,7 +99,6 @@ type tracerConfig struct {
logSQLStatement bool
logConnectionDetails bool
includeParams bool
disableAcquireTracer bool
}

// NewTracer returns a new Tracer.
Expand All @@ -117,7 +118,6 @@ func NewTracer(opts ...Option) *Tracer {
logSQLStatement: true,
logConnectionDetails: true,
includeParams: false,
disableAcquireTracer: false,
}

for _, opt := range opts {
Expand Down Expand Up @@ -146,7 +146,6 @@ func NewTracer(opts ...Option) *Tracer {
prefixQuerySpanName: cfg.prefixQuerySpanName,
logSQLStatement: cfg.logSQLStatement,
includeParams: cfg.includeParams,
disableAcquireTracer: cfg.disableAcquireTracer,
}

tracer.createMetrics()
Expand Down Expand Up @@ -529,126 +528,41 @@ func (t *Tracer) TraceConnectEnd(ctx context.Context, data pgx.TraceConnectEndDa
// TracePrepareStart is called at the beginning of Prepare calls. The returned
// context is used for the rest of the call and will be passed to
// TracePrepareEnd.
func (t *Tracer) TracePrepareStart(ctx context.Context, conn *pgx.Conn, data pgx.TracePrepareStartData) context.Context {
ctx = context.WithValue(ctx, startTimeCtxKey{}, time.Now())

if !trace.SpanFromContext(ctx).IsRecording() {
return ctx
}

optsP := t.spanStartOptionsPool.Get().(*[]trace.SpanStartOption)
defer t.spanStartOptionsPool.Put(optsP)
attrsP := t.attributeSlicePool.Get().(*[]attribute.KeyValue)
defer t.attributeSlicePool.Put(attrsP)

// reslice to empty
opts := (*optsP)[:0]
attrs := (*attrsP)[:0]

attrs = append(attrs, t.tracerAttrs...)

if data.Name != "" {
attrs = append(attrs, PrepareStmtNameKey.String(data.Name))
}

if t.logConnectionDetails && conn != nil {
attrs = append(attrs, connectionAttributesFromConfig(conn.Config())...)
}

attrs = append(attrs, semconv.DBOperationName(t.spanNameCtxFunc(ctx, data.SQL)))

if t.logSQLStatement {
attrs = append(attrs, semconv.DBQueryText(data.SQL))
}

opts = append(opts,
trace.WithSpanKind(trace.SpanKindClient),
trace.WithAttributes(attrs...),
)

spanName := data.SQL
if t.trimQuerySpanName {
spanName = t.spanNameCtxFunc(ctx, data.SQL)
}
if t.prefixQuerySpanName {
spanName = "prepare " + spanName
}

ctx, _ = t.tracer.Start(ctx, spanName, opts...)

return ctx
//
// No span is created for prepare. Instead, the prepare duration is recorded as
// the pgx.prepare.duration attribute (milliseconds) on the parent query span.
func (t *Tracer) TracePrepareStart(ctx context.Context, _ *pgx.Conn, _ pgx.TracePrepareStartData) context.Context {
return context.WithValue(ctx, startTimeCtxKey{}, time.Now())
}

// TracePrepareEnd is called at the end of Prepare calls.
func (t *Tracer) TracePrepareEnd(ctx context.Context, _ *pgx.Conn, data pgx.TracePrepareEndData) {
span := trace.SpanFromContext(ctx)
t.incrementOperationErrorCount(ctx, data.Err, pgxOperationPrepare)
t.recordOperationDuration(ctx, pgxOperationPrepare)

if !span.IsRecording() {
return
if startTime, ok := ctx.Value(startTimeCtxKey{}).(time.Time); ok {
span := trace.SpanFromContext(ctx)
if span.IsRecording() {
span.SetAttributes(PrepareDurationKey.Int64(time.Since(startTime).Milliseconds()))
}
}

recordSpanError(span, data.Err)
span.End()
}

// TraceAcquireStart is called at the beginning of Acquire.
// The returned context is used for the rest of the call and will be passed to the TraceAcquireEnd.
// If WithDisableAcquireTracer was set, then the function is no-op.
func (t *Tracer) TraceAcquireStart(ctx context.Context, pool *pgxpool.Pool, data pgxpool.TraceAcquireStartData) context.Context {
if t.disableAcquireTracer {
return ctx
}

ctx = context.WithValue(ctx, startTimeCtxKey{}, time.Now())

if !trace.SpanFromContext(ctx).IsRecording() {
return ctx
}

optsP := t.spanStartOptionsPool.Get().(*[]trace.SpanStartOption)
defer t.spanStartOptionsPool.Put(optsP)
attrsP := t.attributeSlicePool.Get().(*[]attribute.KeyValue)
defer t.attributeSlicePool.Put(attrsP)

// reslice to empty
opts := (*optsP)[:0]
attrs := (*attrsP)[:0]

attrs = append(attrs, t.tracerAttrs...)

if t.logConnectionDetails && pool != nil && pool.Config() != nil && pool.Config().ConnConfig != nil {
attrs = append(attrs, connectionAttributesFromConfig(pool.Config().ConnConfig)...)
}

opts = append(opts,
trace.WithSpanKind(trace.SpanKindClient),
trace.WithAttributes(attrs...),
)

ctx, _ = t.tracer.Start(ctx, "pool.acquire", opts...)

return ctx
//
// No span is created for pool.acquire. Pool acquire duration is tracked via the
// db.client.operation.duration metric (pgx.operation.type=acquire) and the pgxpool.*
// metrics from RecordStats. As a span it adds noise without actionable signal; pool
// contention is an environmental concern better diagnosed from aggregate metrics.
func (t *Tracer) TraceAcquireStart(ctx context.Context, _ *pgxpool.Pool, _ pgxpool.TraceAcquireStartData) context.Context {
return context.WithValue(ctx, startTimeCtxKey{}, time.Now())
}

// TraceAcquireEnd is called when a connection has been acquired.
// If WithDisableAcquireTracer was set, then the function is no-op.
func (t *Tracer) TraceAcquireEnd(ctx context.Context, _ *pgxpool.Pool, data pgxpool.TraceAcquireEndData) {
if t.disableAcquireTracer {
return
}

span := trace.SpanFromContext(ctx)
t.incrementOperationErrorCount(ctx, data.Err, pgxOperationAcquire)
t.recordOperationDuration(ctx, pgxOperationAcquire)

if !span.IsRecording() {
return
}

recordSpanError(span, data.Err)
span.End()
}

func makeParamsAttribute(args []any) attribute.KeyValue {
Expand Down
96 changes: 96 additions & 0 deletions tracer_span_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,96 @@
package otelpgx

import (
"context"
"testing"

"github.com/jackc/pgx/v5"
"github.com/jackc/pgx/v5/pgxpool"
sdktrace "go.opentelemetry.io/otel/sdk/trace"
"go.opentelemetry.io/otel/sdk/trace/tracetest"
)

func setupTestTracer(t *testing.T) (*Tracer, *tracetest.InMemoryExporter, *sdktrace.TracerProvider) {
t.Helper()

exporter := tracetest.NewInMemoryExporter()
tp := sdktrace.NewTracerProvider(
sdktrace.WithSyncer(exporter),
sdktrace.WithSampler(sdktrace.AlwaysSample()),
)

tracer := NewTracer(WithTracerProvider(tp))
return tracer, exporter, tp
}

func TestTraceAcquire_NoSpan(t *testing.T) {
tracer, exporter, tp := setupTestTracer(t)

parentTracer := tp.Tracer("test")
ctx, parentSpan := parentTracer.Start(context.Background(), "parent")

ctx = tracer.TraceAcquireStart(ctx, nil, pgxpool.TraceAcquireStartData{})
tracer.TraceAcquireEnd(ctx, nil, pgxpool.TraceAcquireEndData{})

parentSpan.End()

spans := exporter.GetSpans()

for _, s := range spans {
if s.Name == "pool.acquire" {
t.Error("pool.acquire span should not be created")
}
}

if len(spans) != 1 {
t.Errorf("expected exactly 1 span (the parent), got %d", len(spans))
}
if spans[0].Name != "parent" {
t.Errorf("expected span name 'parent', got %q", spans[0].Name)
}
}

func TestTracePrepare_NoSpan_SetsAttribute(t *testing.T) {
tracer, exporter, tp := setupTestTracer(t)

parentTracer := tp.Tracer("test")
ctx, parentSpan := parentTracer.Start(context.Background(), "query SELECT 1")

ctx = tracer.TracePrepareStart(ctx, nil, pgx.TracePrepareStartData{
Name: "stmt1",
SQL: "SELECT 1",
})
tracer.TracePrepareEnd(ctx, nil, pgx.TracePrepareEndData{})

parentSpan.End()

spans := exporter.GetSpans()

for _, s := range spans {
if s.Name == "prepare SELECT 1" || s.Name == "SELECT 1" {
t.Errorf("prepare span should not be created, found span %q", s.Name)
}
}

if len(spans) != 1 {
t.Errorf("expected exactly 1 span (the parent), got %d", len(spans))
}

parentAttrs := spans[0].Attributes
var found bool
for _, attr := range parentAttrs {
if attr.Key == PrepareDurationKey {
found = true
if attr.Value.Type().String() != "INT64" {
t.Errorf("expected pgx.prepare.duration to be INT64, got %s", attr.Value.Type())
}
if attr.Value.AsInt64() < 0 {
t.Errorf("expected pgx.prepare.duration >= 0, got %d", attr.Value.AsInt64())
}
}
}

if !found {
t.Error("expected pgx.prepare.duration attribute on parent span, but not found")
}
}
Loading