BatchTracer: expose when pgx began reading each batch query's result

[jalaziz]

Is your feature request related to a problem? Please describe.

TraceBatchQuery carries no timestamp, so a tracer that wants a per-query duration has to invent a heuristic. For example, DataDog chooses: "start a span at query N's hook, finish it at query N+1's hook", but this ends up measuring the following query's processing time.

For [SELECT 1, SELECT * FROM generate_series(1, 3000000)], the above heuristic would result in the fast query's span measuring 100+ ms while the slow streaming query's span measures close to 0 ms. Statements that are slow to process are effectively invisible.

While that is a probably a bug in dd-trace-go, the heuristic still has a flaw that cannot be fixed by tracing libraries: the interval between two consecutive TraceBatchQuery calls also contains any time the application spends between consuming result N and asking for result N+1. This can further skew tracing results as an app that processes rows from result N before calling Exec()/Query() for N+1 has that processing charged to query N+1. Because there is no hook between TraceBatchQuery(N) and TraceBatchQuery(N+1), that gap is unobservable from outside pgx.

Describe the solution you'd like

Add a timestamp to TraceBatchQueryData recording when pgx began reading that query's result:

type TraceBatchQueryData struct {
	SQL        string
	Args       []any
	CommandTag pgconn.CommandTag
	Err        error

	// StartTime is when pgx began reading this query's result. It is not the time
	// the server began executing the query, which the protocol does not report.
	StartTime time.Time
}

The value could be captured just before the reads in batchResults.Exec() / Query() and their pipelineBatchResults counterparts.

Describe alternatives you've considered

1. Adding TraceBatchQueryStart / TraceBatchQueryEnd to BatchTracer. That is why does BatchTracer not have TraceBatchQueryStart/TraceBatchQueryEnd? #1857, which you closed with good reason. As you stated in that ticket, there is no way to know when the server started executing a query. This request is for a different quantity that pgx does know: when pgx began reading the result. While not perfect, it would help provide more granularity when tracing batches. Additionally, the interface would not need to change.

2. Fixing it entirely in the tracer. As stated above, we cannot exclude the application processing time between result reads, because no hook exists in that window.

3. Dropping per-query spans and reporting only the parent batch span. Somewhat more what, but we lose per-statement SQL attribution that makes batch tracing useful in the first place.

Additional context

This still does not make per-query timing accurate in general.

When results are small, PostgreSQL buffers the whole batch, so the first result read blocks until every query has run. Measuring [SELECT 1, SELECT pg_sleep(0.3)], the first read returns after ~300ms, so from the client side the entire batch cost is indistinguishable from waiting for query 1's result. As stated in #1857, no client-side timestamp can untangle that.

Happy to put up a PR if this seems reasonable, or to drop it if you'd rather keep the tracing surface as-is.