-
Notifications
You must be signed in to change notification settings - Fork 304
ateapi: trace PostgreSQL statements in the store #1462
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
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,72 @@ | ||
| // Copyright 2026 Google LLC | ||
| // | ||
| // Licensed under the Apache License, Version 2.0 (the "License"); | ||
| // you may not use this file except in compliance with the License. | ||
| // You may obtain a copy of the License at | ||
| // | ||
| // http://www.apache.org/licenses/LICENSE-2.0 | ||
| // | ||
| // Unless required by applicable law or agreed to in writing, software | ||
| // distributed under the License is distributed on an "AS IS" BASIS, | ||
| // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | ||
| // See the License for the specific language governing permissions and | ||
| // limitations under the License. | ||
|
|
||
| package atepg | ||
|
|
||
| import ( | ||
| "context" | ||
| "errors" | ||
| "strings" | ||
|
|
||
| "github.com/jackc/pgx/v5" | ||
| "go.opentelemetry.io/otel" | ||
| "go.opentelemetry.io/otel/attribute" | ||
| "go.opentelemetry.io/otel/codes" | ||
| "go.opentelemetry.io/otel/trace" | ||
| ) | ||
|
|
||
| // queryTracer is a pgx QueryTracer that opens one client span per statement, | ||
| // so an RPC trace shows where its time went inside PostgreSQL. Statements are | ||
| // parameterized ($1, $2, ...), so db.query.text carries no argument values. | ||
| type queryTracer struct{} | ||
|
|
||
| var _ pgx.QueryTracer = queryTracer{} | ||
|
|
||
| func (queryTracer) TraceQueryStart(ctx context.Context, _ *pgx.Conn, data pgx.TraceQueryStartData) context.Context { | ||
| // Join existing traces only. Statements issued from background work | ||
| // (outbox polling, lease maintenance) carry no span, and opening a root | ||
| // span for each would flood the backend with single-span traces. | ||
| if !trace.SpanContextFromContext(ctx).IsValid() { | ||
| return ctx | ||
| } | ||
|
Comment on lines
+40
to
+42
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Can we use |
||
| ctx, _ = otel.Tracer("atepg").Start(ctx, querySpanName(data.SQL), | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Is an error here an impossible condition? Are we ok swallowing the error?
Collaborator
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The discarded value is the span, not an error. Start cannot fail. Its signature is Start(ctx, name, ...) (context.Context, Span). The OpenTelemetry API is built so tracing never breaks the app: if sampling is off you just get an inert span back, never an error. We discard the span because Start also stores a copy inside the returned context, and that copy is the one we need. The span gets closed in a different function: pgx carries our returned context through the query and passes it to TraceQueryEnd, which retrieves the span with trace.SpanFromContext and ends it. A local span variable would go out of scope as soon as TraceQueryStart returns.
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Can we cache the tracer in a struct field instead of resolving it per statement? |
||
| trace.WithSpanKind(trace.SpanKindClient), | ||
| trace.WithAttributes( | ||
| attribute.String("db.system.name", "postgresql"), | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Can we use
|
||
| attribute.String("db.query.text", data.SQL), | ||
| )) | ||
| return ctx | ||
| } | ||
|
|
||
| func (queryTracer) TraceQueryEnd(ctx context.Context, _ *pgx.Conn, data pgx.TraceQueryEndData) { | ||
| span := trace.SpanFromContext(ctx) | ||
| // pgx.ErrNoRows is an expected lookup outcome (the store maps it to | ||
| // NotFound), not a query failure. | ||
| if data.Err != nil && !errors.Is(data.Err, pgx.ErrNoRows) { | ||
| span.RecordError(data.Err) | ||
| span.SetStatus(codes.Error, data.Err.Error()) | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think we should have access to |
||
| } | ||
|
Comment on lines
+56
to
+59
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Is it possible that this is dead code? |
||
| span.End() | ||
| } | ||
|
|
||
| // querySpanName is "db." plus the statement's leading keyword ("db.SELECT", | ||
| // "db.INSERT", ...): stable low-cardinality names that group by statement | ||
| // kind, with the full text in db.query.text. | ||
| func querySpanName(sql string) string { | ||
| fields := strings.Fields(sql) | ||
| if len(fields) == 0 { | ||
| return "db.query" | ||
| } | ||
| return "db." + strings.ToUpper(fields[0]) | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Can we have See https://opentelemetry.io/docs/specs/semconv/db/database-spans/ |
||
| } | ||
|
Comment on lines
+66
to
+72
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What do you think about skipping tx control statements, or wrap the tx in one INTERNAL span and nest the statements? Otherwise this might get a bit noisy as we are getting regular spans for BEGIN/INSERT/COMMIT/etc. |
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,135 @@ | ||
| // Copyright 2026 Google LLC | ||
| // | ||
| // Licensed under the Apache License, Version 2.0 (the "License"); | ||
| // you may not use this file except in compliance with the License. | ||
| // You may obtain a copy of the License at | ||
| // | ||
| // http://www.apache.org/licenses/LICENSE-2.0 | ||
| // | ||
| // Unless required by applicable law or agreed to in writing, software | ||
| // distributed under the License is distributed on an "AS IS" BASIS, | ||
| // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | ||
| // See the License for the specific language governing permissions and | ||
| // limitations under the License. | ||
|
|
||
| package atepg | ||
|
|
||
| import ( | ||
| "context" | ||
| "errors" | ||
| "testing" | ||
|
|
||
| "github.com/jackc/pgx/v5" | ||
| "go.opentelemetry.io/otel" | ||
| "go.opentelemetry.io/otel/codes" | ||
| sdktrace "go.opentelemetry.io/otel/sdk/trace" | ||
| "go.opentelemetry.io/otel/sdk/trace/tracetest" | ||
| "go.opentelemetry.io/otel/trace" | ||
| ) | ||
|
|
||
| // withRecordingTracer installs a recording global tracer provider for the | ||
| // test and returns the recorder; the previous provider is restored on cleanup. | ||
| func withRecordingTracer(t *testing.T) *tracetest.SpanRecorder { | ||
| t.Helper() | ||
| sr := tracetest.NewSpanRecorder() | ||
| tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) | ||
| prev := otel.GetTracerProvider() | ||
| otel.SetTracerProvider(tp) | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. We have a convention of not swapping the global provider in our tests. |
||
| t.Cleanup(func() { otel.SetTracerProvider(prev) }) | ||
| return sr | ||
| } | ||
|
|
||
| func TestQueryTracerJoinsParentTrace(t *testing.T) { | ||
| sr := withRecordingTracer(t) | ||
| ctx, parent := otel.Tracer("test").Start(context.Background(), "parent") | ||
|
|
||
| qt := queryTracer{} | ||
| qctx := qt.TraceQueryStart(ctx, nil, pgx.TraceQueryStartData{SQL: "SELECT id FROM actors WHERE name = $1"}) | ||
| qt.TraceQueryEnd(qctx, nil, pgx.TraceQueryEndData{}) | ||
| parent.End() | ||
|
|
||
| var dbSpan sdktrace.ReadOnlySpan | ||
| for _, s := range sr.Ended() { | ||
| if s.Name() == "db.SELECT" { | ||
| dbSpan = s | ||
| } | ||
| } | ||
| if dbSpan == nil { | ||
| t.Fatalf("no db.SELECT span recorded; got %d spans", len(sr.Ended())) | ||
| } | ||
| if got, want := dbSpan.Parent().SpanID(), parent.SpanContext().SpanID(); got != want { | ||
| t.Errorf("db span parent = %s, want the RPC span %s", got, want) | ||
| } | ||
| if dbSpan.SpanKind() != trace.SpanKindClient { | ||
| t.Errorf("db span kind = %v, want client", dbSpan.SpanKind()) | ||
| } | ||
| var gotQueryText string | ||
| for _, a := range dbSpan.Attributes() { | ||
| if string(a.Key) == "db.query.text" { | ||
| gotQueryText = a.Value.AsString() | ||
| } | ||
| } | ||
| if gotQueryText != "SELECT id FROM actors WHERE name = $1" { | ||
| t.Errorf("db.query.text = %q", gotQueryText) | ||
| } | ||
| } | ||
|
|
||
| func TestQueryTracerSkipsWithoutParent(t *testing.T) { | ||
| sr := withRecordingTracer(t) | ||
|
|
||
| qt := queryTracer{} | ||
| ctx := context.Background() | ||
| qctx := qt.TraceQueryStart(ctx, nil, pgx.TraceQueryStartData{SQL: "SELECT 1"}) | ||
| if qctx != ctx { | ||
| t.Error("TraceQueryStart without a parent span must return the context unchanged") | ||
| } | ||
| qt.TraceQueryEnd(qctx, nil, pgx.TraceQueryEndData{}) | ||
|
|
||
| if n := len(sr.Ended()); n != 0 { | ||
| t.Errorf("background statement recorded %d spans, want 0", n) | ||
| } | ||
| } | ||
|
|
||
| func TestQueryTracerErrorStatus(t *testing.T) { | ||
| sr := withRecordingTracer(t) | ||
| ctx, parent := otel.Tracer("test").Start(context.Background(), "parent") | ||
| qt := queryTracer{} | ||
|
|
||
| // A real failure marks the span. | ||
| qctx := qt.TraceQueryStart(ctx, nil, pgx.TraceQueryStartData{SQL: "UPDATE actors SET state = $1"}) | ||
| qt.TraceQueryEnd(qctx, nil, pgx.TraceQueryEndData{Err: errors.New("deadlock detected")}) | ||
|
|
||
| // ErrNoRows is an expected lookup outcome and must not mark the span. | ||
| qctx = qt.TraceQueryStart(ctx, nil, pgx.TraceQueryStartData{SQL: "SELECT id FROM actors"}) | ||
| qt.TraceQueryEnd(qctx, nil, pgx.TraceQueryEndData{Err: pgx.ErrNoRows}) | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. |
||
| parent.End() | ||
|
|
||
| var updateStatus, selectStatus codes.Code | ||
| for _, s := range sr.Ended() { | ||
| switch s.Name() { | ||
| case "db.UPDATE": | ||
| updateStatus = s.Status().Code | ||
| case "db.SELECT": | ||
| selectStatus = s.Status().Code | ||
| } | ||
| } | ||
| if updateStatus != codes.Error { | ||
| t.Errorf("failed statement status = %v, want Error", updateStatus) | ||
| } | ||
| if selectStatus == codes.Error { | ||
| t.Error("ErrNoRows must not set Error status") | ||
| } | ||
| } | ||
|
|
||
| func TestQuerySpanName(t *testing.T) { | ||
| for sql, want := range map[string]string{ | ||
| "SELECT 1": "db.SELECT", | ||
| " insert into t values($1)": "db.INSERT", | ||
| "WITH cte AS (SELECT 1) SELECT * FROM cte": "db.WITH", | ||
| "": "db.query", | ||
| } { | ||
| if got := querySpanName(sql); got != want { | ||
| t.Errorf("querySpanName(%q) = %q, want %q", sql, got, want) | ||
| } | ||
| } | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can we add a simple test to assert what the comment states?