sql: give BEGIN, COMMIT, ROLLBACK and savepoint statements their own spans under sql.transaction
I maintainer di solito rispondono entro 1 giorno
Valutazione
Questa issue non è ancora stata valutata.
Descrizione
Written by Claude (Anthropic's AI assistant) on behalf of @austeane. I reproduced everything below myself before filing.
What is the problem this feature would solve?
Packages: effect (effect/sql), seen through @effect/sql-pg
Versions: effect and @effect/sql-pg 4.1.0 (published). The same code is on main at 9394b6d.
A trace of SqlClient.withTransaction cannot show how long the transaction's own control statements took. makeWithTransaction opens one sql.transaction span and, for the outermost transaction, records effect.sql.transaction.commit as an event. An event is an instant. The BEGIN, COMMIT, ROLLBACK, SAVEPOINT, ROLLBACK TO SAVEPOINT and RELEASE SAVEPOINT statements run through options.begin, options.commit and the other callbacks, which call the connection directly and never go through Statement. They get no span and no duration.
That hides the part of a transaction that is often slow in practice: COMMIT. It is where deferred constraints are checked, where the WAL flush happens (more so with synchronous replication), and where a serializable transaction fails. A slow COMMIT shows up as a sql.transaction span that is much longer than the statements inside it, with nothing to say why.
Repro with a local PostgreSQL 16 (any version works). A deferred constraint trigger makes COMMIT take 100 ms, which stands in for the real causes above:
// node repro.mjs postgres://[email protected]:5432/postgres
import { Effect, Redacted, Tracer } from "effect"
import { SqlClient } from "effect/sql"
import { PgClient } from "@effect/sql-pg"
const spans = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
}
})
const program = Effect.gen(function*() {
const sql = yield* SqlClient.SqlClient
yield* sql.unsafe(`create table if not exists spans_demo (id int)`)
yield* sql.unsafe(`create or replace function slow_commit() returns trigger language plpgsql as $$ begin perform pg_sleep(0.1); return null; end $$`)
yield* sql.unsafe(`drop trigger if exists spans_demo_slow on spans_demo`)
yield* sql.unsafe(`create constraint trigger spans_demo_slow after insert on spans_demo deferrable initially deferred for each row execute function slow_commit()`)
spans.length = 0
yield* sql.withTransaction(sql`insert into spans_demo values (1)`)
for (const s of spans) {
const ms = Number((s.status.endTime ?? s.status.startTime) - s.status.startTime) / 1e6
console.log(`${s.name.padEnd(16)} ${ms.toFixed(1).padStart(6)} ms`, s.events.map(([name]) => `event=${name}`).join(" "))
}
}).pipe(
Effect.provide(PgClient.layer({ url: Redacted.make(process.argv[2]), maxConnections: 1 })),
Effect.provideService(Tracer.Tracer, tracer)
)
await Effect.runPromise(program)
process.exit(0)
Output on 4.1.0 (Node 26.12, PostgreSQL 16.11):
sql.transaction 104.6 ms event=effect.sql.transaction.commit
postgres 0.7 ms
The insert took 0.7 ms. The other 104 ms is COMMIT, plus BEGIN and releasing the connection, and the trace has no span for any of them. The same holds for ROLLBACK after a failed effect and for each nested withTransaction, which runs SAVEPOINT and RELEASE SAVEPOINT (or ROLLBACK TO SAVEPOINT) with no span.
#2603 asked for these operations to be wrapped in spans; the fix in #2621 added the sql.transaction span and events, which is what exists today. #8866 aligned that span with the OpenTelemetry database conventions and left the control statements alone.
What is the feature you are proposing to solve the problem?
When SpanPropagationEnabled is on (the existing opt-in, default false, that already adds db.connect and db.client.connection.wait_time_ms), makeWithTransaction wraps each control statement in a client span that is a child of sql.transaction:
| Statement | Span name | db.operation.name |
|---|---|---|
| top-level start | BEGIN {target} |
BEGIN |
| top-level commit | COMMIT {target} |
COMMIT |
| top-level rollback | ROLLBACK {target} |
ROLLBACK |
| nested start | SAVEPOINT {target} |
SAVEPOINT |
| nested failure | ROLLBACK TO SAVEPOINT {target} |
ROLLBACK TO SAVEPOINT |
| nested cleanup | RELEASE SAVEPOINT {target} |
RELEASE SAVEPOINT |
{target} is Statement.spanTarget(spanAttributes), with the fallback Statement.spanName already uses, so a span reads COMMIT postgres. The OpenTelemetry database span conventions name a span {db.operation.name} {target} when no query summary exists and the operation is known and low-cardinality. Unlike a statement, the operation here is known without parsing any SQL. Each span also carries the client's spanAttributes (db.system.name, db.namespace, ...) and ends with the exit of the call, so a failed COMMIT shows as an error on its own span.
Expected trace for the repro above (illustrative, not something 4.1.0 prints):
sql.transaction 104.6 ms
BEGIN postgres 0.4 ms
postgres 0.7 ms insert into spans_demo values (1)
COMMIT postgres 103.1 ms
Notes on the shape:
- I would leave
db.query.textoff these spans.makeWithTransactionreceives effects, not SQL text, and the PostgreSQL client'scommitis a function that checks the result rather than a string. The operation name identifies the statement. - The change is local to
makeWithTransaction: a helper that wrapsoptions.begin,options.commit,options.rollback,options.savepoint,options.rollbackSavepointandoptions.releaseSavepointwhen propagation is on, and leaves the effects untouched when it is off. No driver changes, so every driver that usesmakeWithTransactiongets it. - The existing
effect.sql.transaction.*events stay, so nothing that reads them breaks. - The control spans need
sql.transactionas their parent explicitly (Effect.provideService(Tracer.ParentSpan, span)around each call).Effect.useSpanhands the span to its callback but does not make it the current parent.
I profile an app's transactions with a patched copy of 4.0.7 that does this (a client span around those six calls, behind an opt-in flag), and the commit time is what let me find the slow ones. I am happy to send a PR if you want this.
What alternatives have you considered?
- Always on, without the
SpanPropagationEnabledgate. Statements already get a span unconditionally, so control statements arguably should too. It adds two spans to every transaction, which is why I suggest the opt-in. Easy to flip if you prefer. - Name the spans by target only, like statement spans, and put the operation in
db.operation.name. That is more uniform withStatement.spanName, but every span in a transaction then has the same name and the trace UI cannot tell them apart without opening them. - Derive it from existing data.
sql.transactionduration minus the child statement durations approximates the control statements, but it also contains acquiring the connection and releasing it, and it cannot separateBEGINfromCOMMIT. The event timestamp marks whenCOMMITstarted but not when it ended. - Instrument the driver.
@effect/sql-pghas its own wire-protocol client, so there is nopgpackage to attach OpenTelemetry's instrumentation to.
- Lingua principale
- TypeScript
- Stelle
- 16.7k
- Fork
- 808
- Merge medio
- 11h 3m
- PR unite (30g)
- 840
Preparare l'ambiente
Questo progetto non fornisce container di sviluppo, Dockerfile né guida per i contributori, quindi l'ambiente è a tuo carico: parti dal suo README e consulta la nostra guida al primo contributo per i passaggi generali.
Come iniziare
- Leggi tutta la issue e poi la guida ai contributi del progetto.
- Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
- Fai un fork del repository e lavora su un branch.
- Apri una pull request che faccia riferimento al numero della issue.
Altre issue di Effect-TS/effect
-
PgClient: withTransaction dies instead of failing with SqlError when the server ends the sessionForse già presa @effect-bot l’ha presa oggi. Aperta
Effect-TS/effect#10290 · 1 assegnatario ·
I maintainer di solito rispondono entro 1 giorno
-
shorthand for mapping over tagged union schemaForse già presa @effect-bot l’ha presa oggi. Apertaenhancement
Effect-TS/effect#10286 · 1 assegnatario ·
I maintainer di solito rispondono entro 1 giorno
-
Cluster: A way to remove processed requests from storageForse già presa @effect-bot l’ha presa 1 giorno fa. Apertaenhancement
Effect-TS/effect#10239 · 1 assegnatario ·
I maintainer di solito rispondono entro 1 giorno
-
cluster: a runner that lost its shard lock can still write replies and messages for that shardAperta
Difficoltà 5/5 Più di una settimana Idoneità per principianti 35/100
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 4/5 3-5 giorni Idoneità per principianti 47/100
I maintainer di solito rispondono entro 1 giorno
Tutte le issue di Effect-TS/effect
Issue simili
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 68/100
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 78/100
kunchenguid/gh-axi#247 ·
I maintainer di solito rispondono entro 1 giorno
-
bug
Difficoltà 2/5 1-3 ore Idoneità per principianti 72/100
lidge-jun/opencodex#8101 · 2 commenti ·
I maintainer di solito rispondono entro 1 giorno
-
effort:S P3 refactor
Difficoltà 2/5 1-3 ore Idoneità per principianti 72/100
nightscout/nocturne#3243 ·
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 68/100
JuliusBrussee/caveman#1449 ·
I maintainer di solito rispondono entro 1 giorno