The problem

The project uses Gin, GORM v2, pgx/v5, PostgreSQL, and PgBouncer in transaction pooling mode. We wanted to add Elastic APM so that a request trace would show both the HTTP transaction and its SQL spans: which queries ran, how long they took, and where the time went.

What does “transaction” mean here?

The word appears in three different senses, so let us separate them first.

An APM transaction is a top-level unit in the Elastic APM data model. A web server normally creates one for each incoming HTTP request. apmgin starts it in middleware and stores it in the request context; every span is a child of that transaction.

A database transaction is the usual BEGIN/COMMIT sequence. It has no direct relationship to tracing.

PgBouncer transaction pooling assigns a server connection to a client only for the duration of a database transaction, then returns the connection to the pool.

This is the tree we wanted to see in Kibana:

Transaction  POST /api/v1/orders             400ms   ← apmgin
├─ Span  INSERT INTO "orders" ...             12ms   ← apmsql
├─ Span  SELECT * FROM "users" ...             3ms   ← apmsql
└─ Span  GET awesome-monolith/users/123      150ms   ← external HTTP call

A span cannot exist outside an APM transaction. When we say that “the transaction did not reach the driver,” we mean that the driver had no parent transaction to attach its spans to.

This article follows the investigation from beginning to end: two mistakes in the database driver setup and one Gin option that kept the spans from being recorded.

We had registered apmgin.Middleware on the router, connected GORM through the APM driver, and used WithContext(ctx) in the repositories. After the deployment, HTTP transactions appeared in Kibana, but SQL spans did not.

Act 1: a naive setup and SQLSTATE 42P05

Before adding APM, the database connection looked like this:

// postgres.go, before APM
db, err = gorm.Open(postgres.New(postgres.Config{
	DSN:                  dsn,
	PreferSimpleProtocol: true,
}), &gorm.Config{PrepareStmt: false})

This project used PreferSimpleProtocol: true because its PgBouncer transaction-pooling configuration did not support named prepared statements.

Elastic provides the apmgormv2 module for instrumenting GORM. We connected it like this:

// postgres.go, first APM attempt
import apmpostgres "go.elastic.co/apm/module/apmgormv2/v2/driver/postgres"

db, err = gorm.Open(apmpostgres.Open(dsn), &gorm.Config{PrepareStmt: false})

After deployment, the database still accepted requests, but repositories started returning this error:

ERROR: prepared statement "stmtcache_ffd70399269f8f722..." already exists (SQLSTATE 42P05)

Why it broke

PrepareStmt: false in gorm.Config disables only GORM’s own statement cache. The more consequential detail is that apmpostgres.Open(dsn) builds a postgres.Dialector with DriverName: apmpgxv5.DriverName. The PreferSimpleProtocol option is lost because this wrapper offers no equivalent of postgres.New(Config{...}).

Without an explicit query mode, pgx uses default_query_exec_mode=cache_statement and caches named prepared statements on the connection. PgBouncer transaction pooling may hand a different client the same server connection. In the configuration used by this project, preparing the same statement name on that connection caused 42P05.

The full chain looked like this:

apmpostgres.Open(dsn)
└── postgres.Dialector{DriverName: apmpgxv5.DriverName, DSN: dsn}
    └── no equivalent of postgres.New(Config{...})
        └── no way to pass PreferSimpleProtocol
            └── pgx: default_query_exec_mode = cache_statement
                └── the statement name is derived from the query text,
                    so identical queries receive the same name

client 1 --> PgBouncer --> backend A    PREPARE stmtcache_ffd7...   ok
client 2 --> PgBouncer --> backend A    PREPARE stmtcache_ffd7...   42P05
                           ^
                           the pool returned the same connection,
                           where that prepared-statement name was already used

How we diagnosed it

42P05 comes from PostgreSQL. The query had reached the database and failed on the server. The stack trace pointed to a repository, but that repository had not changed. The driver was now preparing statements in a different mode.

Act 2: fixing the driver without breaking PgBouncer

The obvious attempt is to write this:

// Does not work: PreferSimpleProtocol is ignored.
db, err = gorm.Open(postgres.New(postgres.Config{
	DSN:                  dsn,
	PreferSimpleProtocol: true,
	DriverName:           apmpgxv5.DriverName,
}), &gorm.Config{PrepareStmt: false})

It does not work. The reason is visible in the gorm.io/driver/postgres source:

func (dialector Dialector) Initialize(db *gorm.DB) (err error) {
	...
	if dialector.Conn != nil {
		db.ConnPool = dialector.Conn
	} else if dialector.DriverName != "" {
		// Our branch: call sql.Open immediately with the DSN string.
		db.ConnPool, err = sql.Open(dialector.DriverName, dialector.Config.DSN)
	} else {
		// This branch is unreachable when DriverName is set.
		config, err = pgx.ParseConfig(dialector.Config.DSN)
		if dialector.Config.PreferSimpleProtocol {
			config.DefaultQueryExecMode = pgx.QueryExecModeSimpleProtocol
		}
		db.ConnPool = stdlib.OpenDB(*config)
	}
}

The branching is strict. When DriverName is set, GORM calls sql.Open and does not parse the DSN through pgx. PreferSimpleProtocol is silently ignored, so pgx falls back to the query mode that caused the PgBouncer error.

The fix is to build the pgx configuration before GORM sees it, register that configuration, and pass the resulting connection string to sql.Open:

// postgres.go, working version
import (
	"github.com/jackc/pgx/v5"
	"github.com/jackc/pgx/v5/stdlib"
	apmpgxv5 "go.elastic.co/apm/module/apmsql/v2/pgxv5"
	"gorm.io/driver/postgres"
	"gorm.io/gorm"
)

func Connect(dsn string) *gorm.DB {
	syncOnce.Do(func() {
		// 1. Parse the DSN and select the simple protocol explicitly.
		//    This is where the pgx query mode is set reliably.
		pgxConfig, err := pgx.ParseConfig(dsn)
		if err != nil {
			log.Fatalf("failed to parse postgres config: %v", err)
		}
		pgxConfig.DefaultQueryExecMode = pgx.QueryExecModeSimpleProtocol

		// 2. Register the config with stdlib. The returned string is a key
		//    that lets the driver retrieve this exact configuration.
		registeredDSN := stdlib.RegisterConnConfig(pgxConfig)

		// 3. Give GORM the APM driver and the registered connection string.
		//    sql.Open uses apmpgxv5, while registeredDSN preserves the
		//    simple-protocol setting.
		db, err = gorm.Open(
			postgres.New(postgres.Config{
				DSN:        registeredDSN,
				DriverName: apmpgxv5.DriverName,
			}),
			&gorm.Config{PrepareStmt: false},
		)
		...
	})
	return db
}

sql.Open(apmpgxv5.DriverName, registeredDSN) resolves the registered configuration through pgx stdlib and then wraps the connection with APM instrumentation. QueryExecModeSimpleProtocol remains part of that configuration.

After deployment, 42P05 disappeared. HTTP transactions were still visible in Kibana, but SQL spans were still missing. The driver was now configured correctly, so the problem had to be elsewhere in the request path.

Act 3: spans that exist but are never recorded

The instrumentation followed the documentation:

  • apmgin.Middleware(router) ran first in the middleware chain;
  • GORM used the APM driver;
  • every repository called db.WithContext(ctx).Where(...).

The agent is the go.elastic.co/apm/v2 library running inside the application. It creates transactions and spans, stores them in context, and sends them to APM Server. apmgin and apmsql instrument different layers on top of that agent: apmgin starts a transaction for an HTTP request, while apmsql starts a span for a SQL query. They share the same Transaction and Span types.

We traced the context through the call chain. The apmgin middleware stores the transaction in the request context:

// apmgin/v2 middleware.go
tx, body, req := apmhttp.StartTransactionWithBody(m.tracer, requestName, c.Request)
c.Request = req // The transaction is inside c.Request.Context().

The handler then passes its Gin context to h.useCase.Create:

func (h *OrderHandler) Create(c *gin.Context) {
	user, ok := requireUser(h.base, c)
	...
	// Notice the first argument.
	order, err := h.useCase.Create(c, user.ID, input)
	...
}

That value travels unchanged through the use case and reaches db.WithContext(ctx) in the repository. The apmsql driver asks the agent to start a span. The agent looks up the transaction with ctx.Value(...), gets nil, and takes a normal no-op path:

// apm/v2 span.go
func (tx *Transaction) StartSpanOptions(name, spanType string, opts SpanOptions) *Span {
	if tx == nil {
		return newDroppedSpan() // A supported path, not an error.
	}
	...
}

A dropped span has no tracer. The SQL query still runs, but the span never enters the send queue. No function returns an error. From the agent’s point of view, a missing transaction is valid: a background job may execute without an HTTP request. It cannot distinguish that case from an HTTP request whose transaction was lost along the way. Instrumentation can still call End on the no-op span, so the query completes normally while Kibana receives nothing.

Two probes revealed exactly where the transaction disappeared:

apm.TransactionFromContext(c.Request.Context()) // Handler: transaction found.
apm.TransactionFromContext(ctx)                 // Repository: nil.

Why does c.Request.Context() work while *gin.Context does not?

gin.Context is not context.Context

The handler passes *gin.Context into the use case, and that type formally implements the context.Context interface. This diagram shows the two places where values may live:

*gin.Context                          ← passed to the use case as ctx
├── Keys   map[string]any             ← Gin namespace: c.Set("UserID") / c.Get(...)
├── Request *http.Request             ← pointer field
│   └── ctx context.Context           ← request namespace: Request.Context()
│       └── valueCtx(Sentry hub)      ← set by Sentry middleware
│           └── valueCtx(APM tx)      ← set by apmgin
└── Value()/Deadline()/Done()/Err()
    ├── Value checks Keys
    └── request context is consulted only when fallback is enabled

The APM transaction lives in the request namespace. Without fallback, Gin does not delegate these context.Context methods to c.Request.Context(). The request still contains the data, but code receiving *gin.Context cannot reach it through the interface.

The behavior is explicit in the Gin v1.12 source:

// gin/context.go
func (c *Context) Value(key any) any {
	...
	if val, exists := c.Get(key); exists {
		return val // Gin namespace (Keys).
	}
	if !c.hasRequestContext() {
		return nil // Our case.
	}
	return c.Request.Context().Value(key) // Request namespace, only with fallback.
}

func (c *Context) hasRequestContext() bool {
	hasFallback := c.engine != nil && c.engine.ContextWithFallback // false
	...
}

Value is how code retrieves data from a context. The concrete type behind the interface decides which implementation runs. A standard context searches its WithValue wrappers and finds the transaction. A *gin.Context switches to Gin’s implementation. The transaction remains in c.Request.Context(), but is no longer visible through ctx.Value.

The same applies to Deadline, Done, and Err. Without fallback, gin.Context.Done() returns nil, so downstream code cannot observe client cancellation.

Here is the complete path to the dropped span:

apmgin.Middleware
└── c.Request.Context()   <-- APM transaction lives here

handler   useCase.Create(c, ...)        passes gin.Context instead of request ctx
usecase   repo.Create(ctx, ...)         passes the same gin.Context
repo      db.WithContext(ctx)           sends gin.Context into database/sql
apmsql    apm.StartSpanOptions(ctx)     finds the transaction via ctx.Value(...)

          gin.Context.Value(key)
          ├── Gin service keys           no match
          ├── string keys from c.Set     no match
          └── c.Request.Context()        unavailable because fallback is disabled:
                  hasRequestContext() == false
                  ContextWithFallback = false

          result: nil, span silently dropped

The HTTP transaction remains visible because apmgin starts and finishes it without going through this call chain. That makes the symptom misleading: APM appears to work, but only at the HTTP layer.

Why this is not a Gin bug

Fallback to the request context landed in Gin v1.8.0. Gin v1.8.1 added the ContextWithFallback feature flag; both changes are recorded in the Gin changelog. Delegation is disabled by default for compatibility. With fallback enabled, c.Value(key) may return a value from the request context where older code would receive nil. The option is therefore opt-in, and its documentation is one sentence:

ContextWithFallback enable fallback Context.Deadline(), Context.Done(), Context.Err() and Context.Value() when Context.Request.Context() is not nil.

That one setting affects SQL spans, request cancellation, and deadlines. A single line in the documentation can therefore lead to a long investigation.

A working solution

The application needed one additional router setting:

func (app *app) registryRoutes() {
	app.router = gin.New()
	// Without fallback, gin.Context.Value/Deadline/Done/Err do not delegate
	// to c.Request.Context(), where apmgin stores the transaction.
	// Handlers pass gin.Context to use cases as context.Context, so request
	// context values would otherwise remain invisible downstream.
	app.router.ContextWithFallback = true
	app.router.Use(gin.Recovery())
	app.router.Use(apmgin.Middleware(app.router))
	...
}

The setting changes the behavior of every context-based integration:

System What it reads from ctx Before fallback After fallback
APM SQL spans transaction created by apmgin silently dropped spans are recorded
Request cancellation Done() and Err() client cancellation is hidden cancellation reaches GORM
Timeouts Deadline() deadline is hidden deadline propagates
Other context-based tools their own values hidden downstream values propagate

Request cancellation was the least visible and most expensive symptom. It produced no errors, so nobody was looking for it. A client could disconnect and net/http would cancel the request context, but gin.Context.Done() still returned nil. GORM kept running the transaction for a client that was already gone. The logs looked normal; under load, PostgreSQL continued doing unnecessary work and held transactions open longer than required.

With fallback enabled, cancellation reaches pgx. The driver sends a PostgreSQL cancel request, and the server interrupts the query.

How to debug it

Instrumentation that fails silently is difficult to debug because there is no error or log entry. These checks located the problem:

  1. Add probes at boundaries. Log whether apm.TransactionFromContext(ctx) != nil in the handler, use case, and repository. The boundary where true becomes false is where the context behavior changed.
  2. Run a query without intermediate libraries. Execute sqlDB.QueryRowContext(ctx, "SELECT 1 FROM pg_sleep(0.1)") directly from the handler. If that span appears while the GORM span does not, inspect the GORM-to-database/sql path. If neither appears, the context was lost earlier.
  3. Check sampling before changing code. Set ELASTIC_APM_TRANSACTION_SAMPLE_RATE=1. Unsampled transactions do not retain spans, and exit spans shorter than one millisecond may be discarded. That is why the probe uses pg_sleep(0.1).
  4. Read each wrapper’s implementation. In this case, apmgormv2 had no PreferSimpleProtocol option, the GORM dialector ignored that option when DriverName was set, and Gin kept the request context behind a flag. None of those defaults produced a log entry.

Pitfalls

Gin keys can now fall through to the request context. With fallback enabled, c.Value("key") checks Gin’s store (c.Set) and then the request context. If both stores contain string keys with the same name, the Gin value wins and the shared name creates a hidden dependency. Use string keys for the Gin store and typed keys for the request context.

The flag does not make gin.Context safe to retain. It remains mutable, and its Value result may change between calls. Do not keep it after the request ends. A background task should use context.WithoutCancel(c.Request.Context()) when retaining request values is intentional, or copy only the values it needs.

Passing c.Request.Context() explicitly is another option. In this project, changing more than 50 handlers at once would have produced a large, repetitive review. Enabling the flag was a deliberate compromise: one setting fixed existing call chains, and a code comment records why it is required.

Unit tests may not catch this behavior. Handler tests often use gin.CreateTestContext without an engine configured with ContextWithFallback, while placing the required values directly in Gin’s store. Such tests pass even when observability is broken. An integration test can assert that apm.TransactionFromContext still returns a transaction at a downstream boundary.

The Elastic APM Go Agent is in maintenance mode. The official notice is in the elastic/apm-agent-go repository: bug fixes continue, but the agent will not receive new features. Elastic recommends migrating to OpenTelemetry. That migration does not remove this context issue. OpenTelemetry also carries span context through context.Context, so a gin.Context without fallback hides it in the same way.

Takeaways

  • Following the instrumentation guide does not prove that instrumentation is working. apmgormv2, the GORM dialector, and Gin each accepted the setup without reporting that a relevant option or context value was being ignored.
  • gin.Context formally implements context.Context, but without engine.ContextWithFallback = true, lower layers cannot see values from the request context. That includes the APM transaction, deadline, and cancellation signal.
  • One setting restored SQL spans, request cancellation, timeouts, and values used by other context-based integrations. If a Gin application passes *gin.Context below the handler, check this setting before debugging each integration separately.
  • To locate a missing context value, add the same boolean probe at successive boundaries. The first transition from true to false is more useful than a stack of unrelated logs.

The complete chain was straightforward once every boundary was visible. apmgin stored the APM transaction in the request context, handlers passed gin.Context downstream, and apmsql searched the context it received. Without fallback, the object between them implemented context.Context but did not expose values from c.Request.Context(). The same check applies to any framework that passes its own object in place of a standard context: verify that Value, Done, and Err delegate to the wrapped request context rather than reading only the framework’s internal store.