Set default outcome according to spec (#1160)

Apart from HTTP and gRPC, which set outcome based on
the status code, set the default outcome to "success"
by default, or "failure" if any errors were captured
within the transaction or span.

Author: axw

CHANGELOG.asciidoc

@@ -30,6 +30,7 @@ https://github.com/elastic/apm-agent-go/compare/v1.14.0...master[View commits]
 - module/apmprometheus: add support for mapping prometheus histograms. {pull}1145[#(1145)]
 - Fixed a bug where errors in cloud metadata discovery could lead to the process aborting during initialisation {pull}1158[#(1158)]
 - Fixed a data race related to HTTP request header sanitisation {pull}1159[#(1159)]
+- `apm.CaptureError`, `apm.Error.SetTransaction`, and `apm.Error.SetSpan` will now set the associated transaction or span's default outcome to "failure" {pull}1160[#(1160)]
 
 [[release-notes-1.x]]
 === Go Agent version 1.x

error.go

@@ -247,6 +247,9 @@ func (e *Error) Error() string {
 //
 // If any custom context has been recorded in tx, it will also be carried across
 // to e, but will not override any custom context already recorded on e.
+//
+// SetTransaction also has the effect of setting tx's default outcome to "failure",
+// unless it is explicitly specified by the instrumentation.
 func (e *Error) SetTransaction(tx *Transaction) {
 	tx.mu.RLock()
 	traceContext := tx.traceContext
@@ -255,6 +258,9 @@ func (e *Error) SetTransaction(tx *Transaction) {
 	if !tx.ended() {
 		txType = tx.Type
 		custom = tx.Context.model.Custom
+		tx.TransactionData.mu.Lock()
+		tx.TransactionData.errorCaptured = true
+		tx.TransactionData.mu.Unlock()
 	}
 	tx.mu.RUnlock()
 	e.setSpanData(traceContext, traceContext.Span, txType, custom)
@@ -277,8 +283,19 @@ func (e *Error) SetSpan(s *Span) {
 		if !s.tx.ended() {
 			txType = s.tx.Type
 			custom = s.tx.Context.model.Custom
+			s.tx.TransactionData.mu.Lock()
+			s.tx.TransactionData.errorCaptured = true
+			s.tx.TransactionData.mu.Unlock()
 		}
 		s.tx.mu.RUnlock()
+
+		s.mu.RLock()
+		if !s.ended() {
+			s.SpanData.mu.Lock()
+			s.SpanData.errorCaptured = true
+			s.SpanData.mu.Unlock()
+		}
+		s.mu.RUnlock()
 	}
 	e.setSpanData(s.traceContext, s.transactionID, txType, custom)
 }

internal/apmgodog/suitecontext_test.go

@@ -144,10 +144,26 @@ func (c *featureContext) initScenario(s *godog.ScenarioContext) {
 	s.Step("^user sets transaction outcome to '(.*)'$", c.userSetsTransactionOutcome)
 	s.Step("^span terminates with outcome '(.*)'$", c.spanTerminatesWithOutcome)
 	s.Step("^transaction terminates with outcome '(.*)'$", c.transactionTerminatesWithOutcome)
-	s.Step("^span terminates with an error$", func() error { return c.spanTerminatesWithOutcome("failure") })
-	s.Step("^span terminates without error$", func() error { return c.spanTerminatesWithOutcome("success") })
-	s.Step("^transaction terminates with an error$", func() error { return c.transactionTerminatesWithOutcome("failure") })
-	s.Step("^transaction terminates without error$", func() error { return c.transactionTerminatesWithOutcome("success") })
+	s.Step("^span terminates with an error$", func() error {
+		e := c.tracer.NewError(errors.New("an error"))
+		e.SetSpan(c.span)
+		c.span.End()
+		return nil
+	})
+	s.Step("^span terminates without error$", func() error {
+		c.span.End()
+		return nil
+	})
+	s.Step("^transaction terminates with an error$", func() error {
+		e := c.tracer.NewError(errors.New("an error"))
+		e.SetTransaction(c.transaction)
+		c.transaction.End()
+		return nil
+	})
+	s.Step("^transaction terminates without error$", func() error {
+		c.transaction.End()
+		return nil
+	})
 	s.Step("^span outcome is '(.*)'$", c.spanOutcomeIs)
 	s.Step("^span outcome is \"(.*)\"$", c.spanOutcomeIs)
 	s.Step("^transaction outcome is '(.*)'$", c.transactionOutcomeIs)

span.go

@@ -293,6 +293,8 @@ func (s *Span) SetStacktrace(skip int) {
 	if s.ended() {
 		return
 	}
+	s.SpanData.mu.Lock()
+	defer s.SpanData.mu.Unlock()
 	s.SpanData.setStacktrace(skip + 1)
 }
 
@@ -346,6 +348,13 @@ func (s *Span) End() {
 	}
 	if s.Outcome == "" {
 		s.Outcome = s.Context.outcome()
+		if s.Outcome == "" {
+			if s.errorCaptured {
+				s.Outcome = "failure"
+			} else {
+				s.Outcome = "success"
+			}
+		}
 	}
 	if !s.dropped() && len(s.stacktrace) == 0 &&
 		s.Duration >= s.stackFramesMinDuration {
@@ -561,7 +570,9 @@ type SpanData struct {
 	// Context describes the context in which span occurs.
 	Context SpanContext
 
-	stacktrace []stacktrace.Frame
+	mu            sync.Mutex
+	stacktrace    []stacktrace.Frame
+	errorCaptured bool
 }
 
 func (s *SpanData) setStacktrace(skip int) {

span_test.go

@@ -26,6 +26,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -1263,3 +1264,33 @@ func TestSpanFastExitNoTransaction(t *testing.T) {
 		Dropped: 0,
 	}, transaction.SpanCount)
 }
+
+func TestSpanOutcome(t *testing.T) {
+	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
+		span1, _ := apm.StartSpan(ctx, "name", "type")
+		span1.End()
+
+		span2, _ := apm.StartSpan(ctx, "name", "type")
+		span2.Outcome = "unknown"
+		span2.End()
+
+		span3, _ := apm.StartSpan(ctx, "name", "type")
+		span3.Context.SetHTTPStatusCode(200)
+		span3.End()
+
+		span4, _ := apm.StartSpan(ctx, "name", "type")
+		span4.Context.SetHTTPStatusCode(400)
+		span4.End()
+
+		span5, ctx := apm.StartSpan(ctx, "name", "type")
+		apm.CaptureError(ctx, errors.New("an error")).Send()
+		span5.End()
+	})
+
+	require.Len(t, spans, 5)
+	assert.Equal(t, "success", spans[0].Outcome) // default
+	assert.Equal(t, "unknown", spans[1].Outcome) // specified
+	assert.Equal(t, "success", spans[2].Outcome) // HTTP status < 400
+	assert.Equal(t, "failure", spans[3].Outcome) // HTTP status >= 400
+	assert.Equal(t, "failure", spans[4].Outcome)
+}

transaction.go

@@ -287,6 +287,13 @@ func (tx *Transaction) End() {
 		}
 		if tx.Outcome == "" {
 			tx.Outcome = tx.Context.outcome()
+			if tx.Outcome == "" {
+				if tx.errorCaptured {
+					tx.Outcome = "failure"
+				} else {
+					tx.Outcome = "success"
+				}
+			}
 		}
 		// Hold the transaction data lock to check if the transaction has any
 		// compressed spans in its cache, if so, evict cache and end the span.
@@ -370,6 +377,7 @@ type TransactionData struct {
 	timestamp               time.Time
 
 	mu                sync.Mutex
+	errorCaptured     bool
 	spansCreated      int
 	spansDropped      int
 	childrenTimer     childrenTimer

transaction_test.go

@@ -26,6 +26,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -513,6 +514,40 @@ func TestTransactionDroppedSpansStats(t *testing.T) {
 	})
 }
 
+func TestTransactionOutcome(t *testing.T) {
+	tracer := apmtest.NewRecordingTracer()
+	defer tracer.Close()
+
+	tx1 := tracer.StartTransaction("name", "type")
+	tx1.End()
+
+	tx2 := tracer.StartTransaction("name", "type")
+	tx2.Outcome = "unknown"
+	tx2.End()
+
+	tx3 := tracer.StartTransaction("name", "type")
+	tx3.Context.SetHTTPStatusCode(400)
+	tx3.End()
+
+	tx4 := tracer.StartTransaction("name", "type")
+	tx4.Context.SetHTTPStatusCode(500)
+	tx4.End()
+
+	tx5 := tracer.StartTransaction("name", "type")
+	ctx := apm.ContextWithTransaction(context.Background(), tx5)
+	apm.CaptureError(ctx, errors.New("an error")).Send()
+	tx5.End()
+
+	tracer.Flush(nil)
+	transactions := tracer.Payloads().Transactions
+	require.Len(t, transactions, 5)
+	assert.Equal(t, "success", transactions[0].Outcome) // default
+	assert.Equal(t, "unknown", transactions[1].Outcome) // specified
+	assert.Equal(t, "success", transactions[2].Outcome) // HTTP status < 500
+	assert.Equal(t, "failure", transactions[3].Outcome) // HTTP status >= 500
+	assert.Equal(t, "failure", transactions[4].Outcome)
+}
+
 func BenchmarkTransaction(b *testing.B) {
 	tracer, err := apm.NewTracer("service", "")
 	require.NoError(b, err)