Repository: open-telemetry/opentelemetry-go
Pull request #2163 (2021-08-06 00:16:36)

Support capturing stack trace 
Add `WithStackTrace` option to add a stack trace when using `span.RecordError` or when panic is handled in `span.End`.

codecov[bot]: # [Codecov](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry) Report
> Merging [#2163](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry) (46d54b8) into [main](https://codecov.io/gh/open-telemetry/opentelemetry-go/commit/fcf945a4ab692846177dc7dc6624c0e61f5a54d5?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry) (fcf945a) will **increase** coverage by `0.0%`.
> The diff coverage is `84.0%`.

[![Impacted file tree graph](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163/graphs/tree.svg?width=650&height=150&src=pr&token=8efTmh4kvf&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry)](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry)

```diff
@@          Coverage Diff          @@
##            main   #2163   +/-   ##
=====================================
  Coverage   72.2%   72.2%           
=====================================
  Files        170     170           
  Lines      12076   12101   +25     
=====================================
+ Hits        8724    8745   +21     
- Misses      3111    3114    +3     
- Partials     241     242    +1     
```


| [Impacted Files](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry) | Coverage Δ | |
|---|---|---|
| [sdk/trace/span.go](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry#diff-c2RrL3RyYWNlL3NwYW4uZ28=) | `89.1% <84.0%> (-0.4%)` | :arrow_down: |
| [sdk/resource/resource.go](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry#diff-c2RrL3Jlc291cmNlL3Jlc291cmNlLmdv) | `71.6% <0.0%> (-2.5%)` | :arrow_down: |
| [...s/otlp/otlptrace/internal/connection/connection.go](https://codecov.io/gh/open-telemetry/opentelemetry-go/pull/2163/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=open-telemetry#diff-ZXhwb3J0ZXJzL290bHAvb3RscHRyYWNlL2ludGVybmFsL2Nvbm5lY3Rpb24vY29ubmVjdGlvbi5nbw==) | `16.4% <0.0%> (+1.5%)` | :arrow_up: |

bhautikpip: Any pointers on how to expand this support for [`oteltest`](https://github.com/open-telemetry/opentelemetry-go/blob/main/oteltest/span.go#L85) and [`opentracing`](https://github.com/open-telemetry/opentelemetry-go/blob/39fe8092ed0156b6cbb8225589a81b86124fa491/bridge/opentracing/internal/mock.go#L271) package? Should we also implement the duplicate method of `recordStackTrace` in both of the packages? 
jmacd: It strikes me that the decision to record a stack trace or not ought to be part of SDK configuration, not an instrumentation API. It's a lot like verbosity selection in the logging domain. It's on the same level as choosing your Histogram aggregator buckets in metrics, or sampler configuration to determine which spans record and which do not.
tedsuo: @jmacd I think it might be both. 

I can see why an end user would want a simple way to manually trigger a stack trace. The `WithStackTrace ` API feels clean because it ensures the stack trace overhead is only triggered when the span is actually recording. That's better than the user having to manage the stack trace themselves.

At the same time, I agree with Josh that there probably needs to be a way to trigger stack trace collection from contrib/instrumentation packages, as there is no way for the end user/operator to control that behavior by writing code. 

Like Josh mentioned, controlling these features feels kind of similar to the rules-based methods we've been discussing for controlling sampling and creating views - "when you see this pattern, adjust what you are collecting." 

In general, it's hard to know in advance where you want to record a stack trace, so allowing an operator to control this type of behavior through a configuration language would probably be very valuable.


bhautikpip: I have added `WithStackTrace` API as suggested by @MrAlias which can be used at end of the span or can be added in as an event option. We probably can migrate this to SDK configuration recommended by @jmacd in future probably once we have a path forward for sampling or other config mentioned in the comment above. However, I do not see that as a blocker to merge this PR. 

Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index d8b9979c..492e0227 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -11,6 +11,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm
 ### Added
 
 - Added `ErrorHandlerFunc` to use a function as an `"go.opentelemetry.io/otel".ErrorHandler`. (#2149)
+- Added `"go.opentelemetry.io/otel/trace".WithStackTrace` option to add a stack trace when using `span.RecordError` or when panic is handled in `span.End`. (#2163)
 - Added typed slice attribute types and functionality to the `go.opentelemetry.io/otel/attribute` package to replace the existing array type and functions. (#2162)
   - `BoolSlice`, `IntSlice`, `Int64Slice`, `Float64Slice`, and `StringSlice` replace the use of the `Array` function in the package.
 
diff --git a/sdk/trace/span.go b/sdk/trace/span.go
index 5200fa59..635044f0 100644
--- a/sdk/trace/span.go
+++ b/sdk/trace/span.go
@@ -18,6 +18,7 @@ import (
 	"context"
 	"fmt"
 	"reflect"
+	"runtime"
 	"sync"
 	"time"
 
@@ -235,24 +236,30 @@ func (s *span) End(options ...trace.SpanEndOption) {
 		return
 	}
 
+	config := trace.NewSpanEndConfig(options...)
 	if recovered := recover(); recovered != nil {
 		// Record but don't stop the panic.
 		defer panic(recovered)
-		s.addEvent(
-			semconv.ExceptionEventName,
+		opts := []trace.EventOption{
 			trace.WithAttributes(
 				semconv.ExceptionTypeKey.String(typeStr(recovered)),
 				semconv.ExceptionMessageKey.String(fmt.Sprint(recovered)),
 			),
-		)
+		}
+
+		if config.StackTrace() {
+			opts = append(opts, trace.WithAttributes(
+				semconv.ExceptionStacktraceKey.String(recordStackTrace()),
+			))
+		}
+
+		s.addEvent(semconv.ExceptionEventName, opts...)
 	}
 
 	if s.executionTracerTaskEnd != nil {
 		s.executionTracerTaskEnd()
 	}
 
-	config := trace.NewSpanEndConfig(options...)
-
 	s.mu.Lock()
 	// Setting endTime to non-zero marks the span as ended and not recording.
 	if config.Timestamp().IsZero() {
@@ -286,6 +293,14 @@ func (s *span) RecordError(err error, opts ...trace.EventOption) {
 		semconv.ExceptionTypeKey.String(typeStr(err)),
 		semconv.ExceptionMessageKey.String(err.Error()),
 	))
+
+	c := trace.NewEventConfig(opts...)
+	if c.StackTrace() {
+		opts = append(opts, trace.WithAttributes(
+			semconv.ExceptionStacktraceKey.String(recordStackTrace()),
+		))
+	}
+
 	s.addEvent(semconv.ExceptionEventName, opts...)
 }
 
@@ -298,6 +313,13 @@ func typeStr(i interface{}) string {
 	return fmt.Sprintf("%s.%s", t.PkgPath(), t.Name())
 }
 
+func recordStackTrace() string {
+	stackTrace := make([]byte, 2048)
+	n := runtime.Stack(stackTrace, false)
+
+	return string(stackTrace[0:n])
+}
+
 // AddEvent adds an event with the provided name and options. If this span is
 // not being recorded than this method does nothing.
 func (s *span) AddEvent(name string, o ...trace.EventOption) {
diff --git a/trace/config.go b/trace/config.go
index 87fb4839..3bfb2fff 100644
--- a/trace/config.go
+++ b/trace/config.go
@@ -64,6 +64,7 @@ type SpanConfig struct {
 	links      []Link
 	newRoot    bool
 	spanKind   SpanKind
+	stackTrace bool
 }
 
 // Attributes describe the associated qualities of a Span.
@@ -76,6 +77,11 @@ func (cfg *SpanConfig) Timestamp() time.Time {
 	return cfg.timestamp
 }
 
+// StackTrace checks whether stack trace capturing is enabled.
+func (cfg *SpanConfig) StackTrace() bool {
+	return cfg.stackTrace
+}
+
 // Links are the associations a Span has with other Spans.
 func (cfg *SpanConfig) Links() []Link {
 	return cfg.links
@@ -139,6 +145,7 @@ type SpanEndOption interface {
 type EventConfig struct {
 	attributes []attribute.KeyValue
 	timestamp  time.Time
+	stackTrace bool
 }
 
 // Attributes describe the associated qualities of an Event.
@@ -151,6 +158,11 @@ func (cfg *EventConfig) Timestamp() time.Time {
 	return cfg.timestamp
 }
 
+// StackTrace checks whether stack trace capturing is enabled.
+func (cfg *EventConfig) StackTrace() bool {
+	return cfg.stackTrace
+}
+
 // NewEventConfig applies all the EventOptions to a returned EventConfig. If no
 // timestamp option is passed, the returned EventConfig will have a Timestamp
 // set to the call time, otherwise no validation is performed on the returned
@@ -183,6 +195,12 @@ type SpanStartEventOption interface {
 	EventOption
 }
 
+// SpanEndEventOption are options that can be used at the end of a span, or with an event.
+type SpanEndEventOption interface {
+	SpanEndOption
+	EventOption
+}
+
 type attributeOption []attribute.KeyValue
 
 func (o attributeOption) applySpan(c *SpanConfig) {
@@ -229,6 +247,17 @@ func WithTimestamp(t time.Time) SpanEventOption {
 	return timestampOption(t)
 }
 
+type stackTraceOption bool
+
+func (o stackTraceOption) applyEvent(c *EventConfig)  { c.stackTrace = bool(o) }
+func (o stackTraceOption) applySpan(c *SpanConfig)    { c.stackTrace = bool(o) }
+func (o stackTraceOption) applySpanEnd(c *SpanConfig) { o.applySpan(c) }
+
+// WithStackTrace sets the flag to capture the error with stack trace (e.g. true, false).
+func WithStackTrace(b bool) SpanEndEventOption {
+	return stackTraceOption(b)
+}
+
 // WithLinks adds links to a Span. The links are added to the existing Span
 // links, i.e. this does not overwrite.
 func WithLinks(links ...Link) SpanStartOption {


Test patch:
diff --git a/sdk/trace/trace_test.go b/sdk/trace/trace_test.go
index 01007f2c..8dcc7b5f 100644
--- a/sdk/trace/trace_test.go
+++ b/sdk/trace/trace_test.go
@@ -1154,6 +1154,58 @@ func TestRecordError(t *testing.T) {
 	}
 }
 
+func TestRecordErrorWithStackTrace(t *testing.T) {
+	err := ottest.NewTestError("test error")
+	typ := "go.opentelemetry.io/otel/internal/internaltest.TestError"
+	msg := "test error"
+
+	te := NewTestExporter()
+	tp := NewTracerProvider(WithSyncer(te), WithResource(resource.Empty()))
+	span := startSpan(tp, "RecordError")
+
+	errTime := time.Now()
+	span.RecordError(err, trace.WithTimestamp(errTime), trace.WithStackTrace(true))
+
+	got, err := endSpan(te, span)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	want := &snapshot{
+		spanContext: trace.NewSpanContext(trace.SpanContextConfig{
+			TraceID:    tid,
+			TraceFlags: 0x1,
+		}),
+		parent:   sc.WithRemote(true),
+		name:     "span0",
+		status:   Status{Code: codes.Unset},
+		spanKind: trace.SpanKindInternal,
+		events: []Event{
+			{
+				Name: semconv.ExceptionEventName,
+				Time: errTime,
+				Attributes: []attribute.KeyValue{
+					semconv.ExceptionTypeKey.String(typ),
+					semconv.ExceptionMessageKey.String(msg),
+				},
+			},
+		},
+		instrumentationLibrary: instrumentation.Library{Name: "RecordError"},
+	}
+
+	assert.Equal(t, got.spanContext, want.spanContext)
+	assert.Equal(t, got.parent, want.parent)
+	assert.Equal(t, got.name, want.name)
+	assert.Equal(t, got.status, want.status)
+	assert.Equal(t, got.spanKind, want.spanKind)
+	assert.Equal(t, got.events[0].Attributes[0].Value.AsString(), want.events[0].Attributes[0].Value.AsString())
+	assert.Equal(t, got.events[0].Attributes[1].Value.AsString(), want.events[0].Attributes[1].Value.AsString())
+	gotStackTraceFunctionName := strings.Split(got.events[0].Attributes[2].Value.AsString(), "\n")
+
+	assert.True(t, strings.HasPrefix(gotStackTraceFunctionName[1], "go.opentelemetry.io/otel/sdk/trace.recordStackTrace"))
+	assert.True(t, strings.HasPrefix(gotStackTraceFunctionName[3], "go.opentelemetry.io/otel/sdk/trace.(*span).RecordError"))
+}
+
 func TestRecordErrorNil(t *testing.T) {
 	te := NewTestExporter()
 	tp := NewTracerProvider(WithSyncer(te), WithResource(resource.Empty()))
@@ -1361,6 +1413,32 @@ func TestSpanCapturesPanic(t *testing.T) {
 	})
 }
 
+func TestSpanCapturesPanicWithStackTrace(t *testing.T) {
+	te := NewTestExporter()
+	tp := NewTracerProvider(WithSyncer(te), WithResource(resource.Empty()))
+	_, span := tp.Tracer("CatchPanic").Start(
+		context.Background(),
+		"span",
+	)
+
+	f := func() {
+		defer span.End(trace.WithStackTrace(true))
+		panic(errors.New("error message"))
+	}
+	require.PanicsWithError(t, "error message", f)
+	spans := te.Spans()
+	require.Len(t, spans, 1)
+	require.Len(t, spans[0].Events(), 1)
+	assert.Equal(t, spans[0].Events()[0].Name, semconv.ExceptionEventName)
+	assert.Equal(t, spans[0].Events()[0].Attributes[0].Value.AsString(), "*errors.errorString")
+	assert.Equal(t, spans[0].Events()[0].Attributes[1].Value.AsString(), "error message")
+
+	gotStackTraceFunctionName := strings.Split(spans[0].Events()[0].Attributes[2].Value.AsString(), "\n")
+	fmt.Println(strings.Split(gotStackTraceFunctionName[1], "(0x")[0])
+	assert.True(t, strings.HasPrefix(gotStackTraceFunctionName[1], "go.opentelemetry.io/otel/sdk/trace.recordStackTrace"))
+	assert.True(t, strings.HasPrefix(gotStackTraceFunctionName[3], "go.opentelemetry.io/otel/sdk/trace.(*span).End"))
+}
+
 func TestReadOnlySpan(t *testing.T) {
 	kv := attribute.String("foo", "bar")
 
diff --git a/trace/config_test.go b/trace/config_test.go
index 3b8c9b18..2b4ab965 100644
--- a/trace/config_test.go
+++ b/trace/config_test.go
@@ -174,6 +174,39 @@ func TestNewSpanConfig(t *testing.T) {
 	}
 }
 
+func TestEndSpanConfig(t *testing.T) {
+	timestamp := time.Unix(0, 0)
+
+	tests := []struct {
+		options  []SpanEndOption
+		expected *SpanConfig
+	}{
+		{
+			[]SpanEndOption{},
+			new(SpanConfig),
+		},
+		{
+			[]SpanEndOption{
+				WithStackTrace(true),
+			},
+			&SpanConfig{
+				stackTrace: true,
+			},
+		},
+		{
+			[]SpanEndOption{
+				WithTimestamp(timestamp),
+			},
+			&SpanConfig{
+				timestamp: timestamp,
+			},
+		},
+	}
+	for _, test := range tests {
+		assert.Equal(t, test.expected, NewSpanEndConfig(test.options...))
+	}
+}
+
 func TestTracerConfig(t *testing.T) {
 	v1 := "semver:0.0.1"
 	v2 := "semver:1.0.0"