module/apmsql: fix error capture

We were passing the (initial nil) error value
to finishSpan by mistake. Pass a pointer to the
result error var instead, to capture the final
value.

Fixes #159

CHANGELOG.md

@@ -13,6 +13,7 @@
  - module/apmgocql: new instrumentation module, providing an observer for gocql (#148)
  - Add ELASTIC\_APM\_SERVER\_TIMEOUT config (#157)
  - Add ELASTIC\_APM\_IGNORE\_URLS config (#158)
+ - module/apmsql: fix a bug preventing errors from being captured (#160)
 
 ## [v0.4.0](https://github.com/elastic/apm-agent-go/releases/tag/v0.4.0)
 

module/apmsql/apmsql_go110_test.go

@@ -19,7 +19,7 @@ func TestConnect(t *testing.T) {
 
 	// Note: only in Go 1.10 do we have context during connection.
 
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		err := db.PingContext(ctx)
 		assert.NoError(t, err)
 	})

module/apmsql/apmsql_test.go

@@ -21,7 +21,7 @@ func TestPingContext(t *testing.T) {
 	defer db.Close()
 
 	db.Ping() // connect
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		err := db.PingContext(ctx)
 		assert.NoError(t, err)
 	})
@@ -36,7 +36,7 @@ func TestExecContext(t *testing.T) {
 	defer db.Close()
 
 	db.Ping() // connect
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		_, err := db.ExecContext(ctx, "CREATE TABLE foo (bar INT)")
 		require.NoError(t, err)
 	})
@@ -53,7 +53,7 @@ func TestQueryContext(t *testing.T) {
 	_, err = db.Exec("CREATE TABLE foo (bar INT)")
 	require.NoError(t, err)
 
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		rows, err := db.QueryContext(ctx, "SELECT * FROM foo")
 		require.NoError(t, err)
 		rows.Close()
@@ -78,7 +78,7 @@ func TestPrepareContext(t *testing.T) {
 	defer db.Close()
 
 	db.Ping() // connect
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		stmt, err := db.PrepareContext(ctx, "CREATE TABLE foo (bar INT)")
 		require.NoError(t, err)
 		defer stmt.Close()
@@ -102,7 +102,7 @@ func TestStmtExecContext(t *testing.T) {
 	require.NoError(t, err)
 	defer stmt.Close()
 
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		_, err = stmt.ExecContext(ctx, sql.Named("ceil", 999))
 		require.NoError(t, err)
 	})
@@ -123,7 +123,7 @@ func TestStmtQueryContext(t *testing.T) {
 	require.NoError(t, err)
 	defer stmt.Close()
 
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		rows, err := stmt.QueryContext(ctx)
 		require.NoError(t, err)
 		rows.Close()
@@ -145,7 +145,7 @@ func TestTxStmtQueryContext(t *testing.T) {
 	require.NoError(t, err)
 	defer stmt.Close()
 
-	tx := withTransaction(t, func(ctx context.Context) {
+	tx, _ := withTransaction(t, func(ctx context.Context) {
 		tx, err := db.BeginTx(ctx, nil)
 		require.NoError(t, err)
 		defer tx.Rollback()
@@ -160,7 +160,24 @@ func TestTxStmtQueryContext(t *testing.T) {
 	assert.Equal(t, "db.sqlite3.query", tx.Spans[0].Type)
 }
 
-func withTransaction(t *testing.T, f func(ctx context.Context)) model.Transaction {
+func TestCaptureErrors(t *testing.T) {
+	db, err := apmsql.Open("sqlite3", ":memory:")
+	require.NoError(t, err)
+	defer db.Close()
+
+	db.Ping() // connect
+	tx, errors := withTransaction(t, func(ctx context.Context) {
+		_, err := db.QueryContext(ctx, "SELECT * FROM thin_air")
+		require.Error(t, err)
+	})
+	require.Len(t, tx.Spans, 1)
+	require.Len(t, errors, 1)
+	assert.Equal(t, "SELECT FROM thin_air", tx.Spans[0].Name)
+	assert.Equal(t, "db.sqlite3.query", tx.Spans[0].Type)
+	assert.Equal(t, "no such table: thin_air", errors[0].Exception.Message)
+}
+
+func withTransaction(t *testing.T, f func(ctx context.Context)) (model.Transaction, []*model.Error) {
 	tracer, transport := transporttest.NewRecorderTracer()
 	defer tracer.Close()
 
@@ -171,8 +188,11 @@ func withTransaction(t *testing.T, f func(ctx context.Context)) model.Transactio
 	tx.End()
 	tracer.Flush(nil)
 	payloads := transport.Payloads()
-	require.Len(t, payloads, 1)
-	transactions := payloads[0].Transactions()
+	var errors []*model.Error
+	if len(payloads) == 2 {
+		errors = payloads[0].Errors()
+	}
+	transactions := payloads[len(payloads)-1].Transactions()
 	require.Len(t, transactions, 1)
-	return transactions[0]
+	return transactions[0], errors
 }

module/apmsql/conn.go

@@ -57,8 +57,8 @@ func (c *conn) startSpan(ctx context.Context, name, spanType, stmt string) (*ela
 	return span, ctx
 }
 
-func (c *conn) finishSpan(ctx context.Context, span *elasticapm.Span, resultError error) {
-	if resultError == driver.ErrSkip {
+func (c *conn) finishSpan(ctx context.Context, span *elasticapm.Span, resultError *error) {
+	if *resultError == driver.ErrSkip {
 		// TODO(axw) mark span as abandoned,
 		// so it's not sent and not counted
 		// in the span limit. Ideally remove
@@ -67,7 +67,7 @@ func (c *conn) finishSpan(ctx context.Context, span *elasticapm.Span, resultErro
 		return
 	}
 	span.End()
-	if e := elasticapm.CaptureError(ctx, resultError); e != nil {
+	if e := elasticapm.CaptureError(ctx, *resultError); e != nil {
 		e.Send()
 	}
 }
@@ -77,7 +77,7 @@ func (c *conn) Ping(ctx context.Context) (resultError error) {
 		return nil
 	}
 	span, ctx := c.startSpan(ctx, "ping", c.driver.pingSpanType, "")
-	defer c.finishSpan(ctx, span, resultError)
+	defer c.finishSpan(ctx, span, &resultError)
 	return c.pinger.Ping(ctx)
 }
 
@@ -86,7 +86,7 @@ func (c *conn) QueryContext(ctx context.Context, query string, args []driver.Nam
 		return nil, driver.ErrSkip
 	}
 	span, ctx := c.startStmtSpan(ctx, query, c.driver.querySpanType)
-	defer c.finishSpan(ctx, span, resultError)
+	defer c.finishSpan(ctx, span, &resultError)
 
 	if c.queryerContext != nil {
 		return c.queryerContext.QueryContext(ctx, query, args)
@@ -109,7 +109,7 @@ func (*conn) Query(query string, args []driver.Value) (driver.Rows, error) {
 
 func (c *conn) PrepareContext(ctx context.Context, query string) (_ driver.Stmt, resultError error) {
 	span, ctx := c.startStmtSpan(ctx, query, c.driver.prepareSpanType)
-	defer c.finishSpan(ctx, span, resultError)
+	defer c.finishSpan(ctx, span, &resultError)
 	var stmt driver.Stmt
 	var err error
 	if c.connPrepareContext != nil {
@@ -136,7 +136,7 @@ func (c *conn) ExecContext(ctx context.Context, query string, args []driver.Name
 		return nil, driver.ErrSkip
 	}
 	span, ctx := c.startStmtSpan(ctx, query, c.driver.execSpanType)
-	defer c.finishSpan(ctx, span, resultError)
+	defer c.finishSpan(ctx, span, &resultError)
 
 	if c.execerContext != nil {
 		return c.execerContext.ExecContext(ctx, query, args)

module/apmsql/stmt.go

@@ -46,7 +46,7 @@ func (s *stmt) ColumnConverter(idx int) driver.ValueConverter {
 
 func (s *stmt) ExecContext(ctx context.Context, args []driver.NamedValue) (_ driver.Result, resultError error) {
 	span, ctx := s.startSpan(ctx, s.conn.driver.execSpanType)
-	defer s.conn.finishSpan(ctx, span, resultError)
+	defer s.conn.finishSpan(ctx, span, &resultError)
 	if s.stmtExecContext != nil {
 		return s.stmtExecContext.ExecContext(ctx, args)
 	}
@@ -64,7 +64,7 @@ func (s *stmt) ExecContext(ctx context.Context, args []driver.NamedValue) (_ dri
 
 func (s *stmt) QueryContext(ctx context.Context, args []driver.NamedValue) (_ driver.Rows, resultError error) {
 	span, ctx := s.startSpan(ctx, s.conn.driver.querySpanType)
-	defer s.conn.finishSpan(ctx, span, resultError)
+	defer s.conn.finishSpan(ctx, span, &resultError)
 	if s.stmtQueryContext != nil {
 		return s.stmtQueryContext.QueryContext(ctx, args)
 	}