Skip to content

Commit 9f4c7ea

Browse files
otternqotternq
committed
observability: fix err access scope to correctly retrieve it on defer
Fixes a bug in which we mistakenly used the earliest value of err which was always nil, when measuring latency. The fix here is to invoke the latency measuring closure inside a defer to correctly capture the latest value of the named err value.
1 parent d368279 commit 9f4c7ea

File tree

1 file changed

+84
-14
lines changed

1 file changed

+84
-14
lines changed

‎driver.go‎

Lines changed: 84 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -133,7 +133,12 @@ type ocConn struct {
133133
}
134134

135135
func (c ocConn) Ping(ctx context.Context) (err error) {
136-
defer recordCallStats(ctx, "go.sql.ping", c.options.InstanceName)(err)
136+
onDeferWithErr := recordCallStats(ctx, "go.sql.ping", c.options.InstanceName)
137+
defer func() {
138+
// Invoking this function in a defer so that we can capture
139+
// the value of err as set on function exit.
140+
onDeferWithErr(err)
141+
}()
137142

138143
if c.options.Ping && (c.options.AllowRoot || trace.FromContext(ctx) != nil) {
139144
var span *trace.Span
@@ -164,7 +169,12 @@ func (c ocConn) Ping(ctx context.Context) (err error) {
164169
}
165170

166171
func (c ocConn) Exec(query string, args []driver.Value) (res driver.Result, err error) {
167-
defer recordCallStats(context.Background(), "go.sql.exec", c.options.InstanceName)(err)
172+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.exec", c.options.InstanceName)
173+
defer func() {
174+
// Invoking this function in a defer so that we can capture
175+
// the value of err as set on function exit.
176+
onDeferWithErr(err)
177+
}()
168178

169179
if exec, ok := c.parent.(driver.Execer); ok {
170180
if !c.options.AllowRoot {
@@ -208,7 +218,12 @@ func (c ocConn) Exec(query string, args []driver.Value) (res driver.Result, err
208218
}
209219

210220
func (c ocConn) ExecContext(ctx context.Context, query string, args []driver.NamedValue) (res driver.Result, err error) {
211-
defer recordCallStats(ctx, "go.sql.exec", c.options.InstanceName)(err)
221+
onDeferWithErr := recordCallStats(ctx, "go.sql.exec", c.options.InstanceName)
222+
defer func() {
223+
// Invoking this function in a defer so that we can capture
224+
// the value of err as set on function exit.
225+
onDeferWithErr(err)
226+
}()
212227

213228
if execCtx, ok := c.parent.(driver.ExecerContext); ok {
214229
parentSpan := trace.FromContext(ctx)
@@ -253,7 +268,12 @@ func (c ocConn) ExecContext(ctx context.Context, query string, args []driver.Nam
253268
}
254269

255270
func (c ocConn) Query(query string, args []driver.Value) (rows driver.Rows, err error) {
256-
defer recordCallStats(context.Background(), "go.sql.query", c.options.InstanceName)(err)
271+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.query", c.options.InstanceName)
272+
defer func() {
273+
// Invoking this function in a defer so that we can capture
274+
// the value of err as set on function exit.
275+
onDeferWithErr(err)
276+
}()
257277

258278
if queryer, ok := c.parent.(driver.Queryer); ok {
259279
if !c.options.AllowRoot {
@@ -298,7 +318,12 @@ func (c ocConn) Query(query string, args []driver.Value) (rows driver.Rows, err
298318
}
299319

300320
func (c ocConn) QueryContext(ctx context.Context, query string, args []driver.NamedValue) (rows driver.Rows, err error) {
301-
defer recordCallStats(ctx, "go.sql.query", c.options.InstanceName)(err)
321+
onDeferWithErr := recordCallStats(ctx, "go.sql.query", c.options.InstanceName)
322+
defer func() {
323+
// Invoking this function in a defer so that we can capture
324+
// the value of err as set on function exit.
325+
onDeferWithErr(err)
326+
}()
302327

303328
if queryerCtx, ok := c.parent.(driver.QueryerContext); ok {
304329
parentSpan := trace.FromContext(ctx)
@@ -344,7 +369,12 @@ func (c ocConn) QueryContext(ctx context.Context, query string, args []driver.Na
344369
}
345370

346371
func (c ocConn) Prepare(query string) (stmt driver.Stmt, err error) {
347-
defer recordCallStats(context.Background(), "go.sql.prepare", c.options.InstanceName)(err)
372+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.prepare", c.options.InstanceName)
373+
defer func() {
374+
// Invoking this function in a defer so that we can capture
375+
// the value of err as set on function exit.
376+
onDeferWithErr(err)
377+
}()
348378

349379
if c.options.AllowRoot {
350380
_, span := trace.StartSpan(context.Background(), "sql:prepare",
@@ -383,7 +413,12 @@ func (c *ocConn) Begin() (driver.Tx, error) {
383413
}
384414

385415
func (c *ocConn) PrepareContext(ctx context.Context, query string) (stmt driver.Stmt, err error) {
386-
defer recordCallStats(ctx, "go.sql.prepare", c.options.InstanceName)(err)
416+
onDeferWithErr := recordCallStats(ctx, "go.sql.prepare", c.options.InstanceName)
417+
defer func() {
418+
// Invoking this function in a defer so that we can capture
419+
// the value of err as set on function exit.
420+
onDeferWithErr(err)
421+
}()
387422

388423
var span *trace.Span
389424
attrs := append([]trace.Attribute(nil), c.options.DefaultAttributes...)
@@ -419,7 +454,12 @@ func (c *ocConn) PrepareContext(ctx context.Context, query string) (stmt driver.
419454
}
420455

421456
func (c *ocConn) BeginTx(ctx context.Context, opts driver.TxOptions) (tx driver.Tx, err error) {
422-
defer recordCallStats(ctx, "go.sql.begin", c.options.InstanceName)(err)
457+
onDeferWithErr := recordCallStats(ctx, "go.sql.begin", c.options.InstanceName)
458+
defer func() {
459+
// Invoking this function in a defer so that we can capture
460+
// the value of err as set on function exit.
461+
onDeferWithErr(err)
462+
}()
423463

424464
if !c.options.AllowRoot && trace.FromContext(ctx) == nil {
425465
if connBeginTx, ok := c.parent.(driver.ConnBeginTx); ok {
@@ -528,7 +568,12 @@ type ocStmt struct {
528568
}
529569

530570
func (s ocStmt) Exec(args []driver.Value) (res driver.Result, err error) {
531-
defer recordCallStats(context.Background(), "go.sql.stmt.exec", s.options.InstanceName)(err)
571+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.stmt.exec", s.options.InstanceName)
572+
defer func() {
573+
// Invoking this function in a defer so that we can capture
574+
// the value of err as set on function exit.
575+
onDeferWithErr(err)
576+
}()
532577

533578
if !s.options.AllowRoot {
534579
return s.parent.Exec(args)
@@ -578,7 +623,12 @@ func (s ocStmt) NumInput() int {
578623
}
579624

580625
func (s ocStmt) Query(args []driver.Value) (rows driver.Rows, err error) {
581-
defer recordCallStats(context.Background(), "go.sql.stmt.query", s.options.InstanceName)(err)
626+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.stmt.query", s.options.InstanceName)
627+
defer func() {
628+
// Invoking this function in a defer so that we can capture
629+
// the value of err as set on function exit.
630+
onDeferWithErr(err)
631+
}()
582632

583633
if !s.options.AllowRoot {
584634
return s.parent.Query(args)
@@ -619,7 +669,12 @@ func (s ocStmt) Query(args []driver.Value) (rows driver.Rows, err error) {
619669
}
620670

621671
func (s ocStmt) ExecContext(ctx context.Context, args []driver.NamedValue) (res driver.Result, err error) {
622-
defer recordCallStats(ctx, "go.sql.stmt.exec", s.options.InstanceName)(err)
672+
onDeferWithErr := recordCallStats(ctx, "go.sql.stmt.exec", s.options.InstanceName)
673+
defer func() {
674+
// Invoking this function in a defer so that we can capture
675+
// the value of err as set on function exit.
676+
onDeferWithErr(err)
677+
}()
623678

624679
parentSpan := trace.FromContext(ctx)
625680
if !s.options.AllowRoot && parentSpan == nil {
@@ -664,7 +719,12 @@ func (s ocStmt) ExecContext(ctx context.Context, args []driver.NamedValue) (res
664719
}
665720

666721
func (s ocStmt) QueryContext(ctx context.Context, args []driver.NamedValue) (rows driver.Rows, err error) {
667-
defer recordCallStats(ctx, "go.sql.stmt.query", s.options.InstanceName)(err)
722+
onDeferWithErr := recordCallStats(ctx, "go.sql.stmt.query", s.options.InstanceName)
723+
defer func() {
724+
// Invoking this function in a defer so that we can capture
725+
// the value of err as set on function exit.
726+
onDeferWithErr(err)
727+
}()
668728

669729
parentSpan := trace.FromContext(ctx)
670730
if !s.options.AllowRoot && parentSpan == nil {
@@ -873,7 +933,12 @@ type ocTx struct {
873933
}
874934

875935
func (t ocTx) Commit() (err error) {
876-
defer recordCallStats(context.Background(), "go.sql.commit", t.options.InstanceName)(err)
936+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.commit", t.options.InstanceName)
937+
defer func() {
938+
// Invoking this function in a defer so that we can capture
939+
// the value of err as set on function exit.
940+
onDeferWithErr(err)
941+
}()
877942

878943
_, span := trace.StartSpan(t.ctx, "sql:commit",
879944
trace.WithSpanKind(trace.SpanKindClient),
@@ -892,7 +957,12 @@ func (t ocTx) Commit() (err error) {
892957
}
893958

894959
func (t ocTx) Rollback() (err error) {
895-
defer recordCallStats(context.Background(), "go.sql.rollback", t.options.InstanceName)(err)
960+
onDeferWithErr := recordCallStats(context.Background(), "go.sql.rollback", t.options.InstanceName)
961+
defer func() {
962+
// Invoking this function in a defer so that we can capture
963+
// the value of err as set on function exit.
964+
onDeferWithErr(err)
965+
}()
896966

897967
_, span := trace.StartSpan(t.ctx, "sql:rollback",
898968
trace.WithSpanKind(trace.SpanKindClient),

0 commit comments

Comments
 (0)