github.com/waldiirawan/apm-agent-go/v2@v2.2.2/span_test.go (about)

     1  // Licensed to Elasticsearch B.V. under one or more contributor
     2  // license agreements. See the NOTICE file distributed with
     3  // this work for additional information regarding copyright
     4  // ownership. Elasticsearch B.V. licenses this file to you under
     5  // the Apache License, Version 2.0 (the "License"); you may
     6  // not use this file except in compliance with the License.
     7  // You may obtain a copy of the License at
     8  //
     9  //     http://www.apache.org/licenses/LICENSE-2.0
    10  //
    11  // Unless required by applicable law or agreed to in writing,
    12  // software distributed under the License is distributed on an
    13  // "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
    14  // KIND, either express or implied.  See the License for the
    15  // specific language governing permissions and limitations
    16  // under the License.
    17  
    18  package apm_test
    19  
    20  import (
    21  	"context"
    22  	"fmt"
    23  	"os"
    24  	"sort"
    25  	"sync"
    26  	"testing"
    27  	"time"
    28  
    29  	"github.com/pkg/errors"
    30  	"github.com/stretchr/testify/assert"
    31  	"github.com/stretchr/testify/require"
    32  
    33  	"github.com/waldiirawan/apm-agent-go/v2"
    34  	"github.com/waldiirawan/apm-agent-go/v2/apmtest"
    35  	"github.com/waldiirawan/apm-agent-go/v2/model"
    36  	"github.com/waldiirawan/apm-agent-go/v2/transport/transporttest"
    37  )
    38  
    39  func TestStartSpanTransactionNotSampled(t *testing.T) {
    40  	tracer, _ := apm.NewTracer("tracer_testing", "")
    41  	defer tracer.Close()
    42  	// sample nothing
    43  	tracer.SetSampler(apm.NewRatioSampler(0))
    44  
    45  	tx := tracer.StartTransaction("name", "type")
    46  	assert.False(t, tx.Sampled())
    47  	span := tx.StartSpan("name", "type", nil)
    48  	assert.True(t, span.Dropped())
    49  }
    50  
    51  func TestTracerStartSpan(t *testing.T) {
    52  	tracer, r := transporttest.NewRecorderTracer()
    53  	defer tracer.Close()
    54  
    55  	txTimestamp := time.Now()
    56  	tx := tracer.StartTransactionOptions("name", "type", apm.TransactionOptions{
    57  		Start: txTimestamp,
    58  	})
    59  	txTraceContext := tx.TraceContext()
    60  	span0 := tx.StartSpan("name", "type", nil)
    61  	span0TraceContext := span0.TraceContext()
    62  	span0.End()
    63  	tx.End()
    64  
    65  	// Even if the transaction and parent span have been ended,
    66  	// it is possible to report a span with their IDs.
    67  	tracer.StartSpan("name", "type",
    68  		txTraceContext.Span,
    69  		apm.SpanOptions{
    70  			Parent: span0TraceContext,
    71  			Start:  txTimestamp.Add(time.Second),
    72  		},
    73  	).End()
    74  
    75  	tracer.Flush(nil)
    76  	payloads := r.Payloads()
    77  	assert.Len(t, payloads.Transactions, 1)
    78  	assert.Len(t, payloads.Spans, 2)
    79  
    80  	assert.Equal(t, payloads.Transactions[0].ID, payloads.Spans[0].ParentID)
    81  	assert.Equal(t, payloads.Spans[0].ID, payloads.Spans[1].ParentID)
    82  	for _, span := range payloads.Spans {
    83  		assert.Equal(t, payloads.Transactions[0].TraceID, span.TraceID)
    84  		assert.Equal(t, payloads.Transactions[0].ID, span.TransactionID)
    85  	}
    86  	assert.NotZero(t, payloads.Spans[1].ID)
    87  
    88  	assert.Equal(t, time.Time(payloads.Transactions[0].Timestamp).Add(time.Second), time.Time(payloads.Spans[1].Timestamp))
    89  
    90  	// The span created after the transaction (obviously?)
    91  	// doesn't get included in the transaction's span count.
    92  	assert.Equal(t, 1, payloads.Transactions[0].SpanCount.Started)
    93  }
    94  
    95  func TestSpanParentID(t *testing.T) {
    96  	tracer := apmtest.NewRecordingTracer()
    97  	defer tracer.Close()
    98  
    99  	tx := tracer.StartTransaction("name", "type")
   100  	span := tx.StartSpan("name", "type", nil)
   101  	traceContext := tx.TraceContext()
   102  	parentID := span.ParentID()
   103  
   104  	span.End()
   105  	tx.End()
   106  	// Assert that the parentID is not empty when the span hasn't been ended.
   107  	// And that the Span's parentID equals the traceContext Span.
   108  	assert.NotEqual(t, parentID, apm.SpanID{})
   109  	assert.Equal(t, traceContext.Span, parentID)
   110  
   111  	// Assert that the parentID is not empty after the span has ended.
   112  	assert.NotZero(t, span.ParentID())
   113  	assert.Equal(t, traceContext.Span, span.ParentID())
   114  
   115  	tracer.Flush(nil)
   116  	payloads := tracer.Payloads()
   117  	require.Len(t, payloads.Spans, 1)
   118  	assert.Equal(t, model.SpanID(parentID), payloads.Spans[0].ParentID)
   119  }
   120  
   121  func TestSpanEnsureType(t *testing.T) {
   122  	tracer := apmtest.NewRecordingTracer()
   123  	defer tracer.Close()
   124  
   125  	tx := tracer.StartTransaction("name", "type")
   126  	span := tx.StartSpan("name", "", nil)
   127  	span.End()
   128  	tx.End()
   129  	tracer.Flush(nil)
   130  
   131  	payloads := tracer.Payloads()
   132  	require.Len(t, payloads.Spans, 1)
   133  
   134  	assert.Equal(t, "custom", payloads.Spans[0].Type)
   135  }
   136  
   137  func TestSpanLink(t *testing.T) {
   138  	tracer := apmtest.NewRecordingTracer()
   139  	defer tracer.Close()
   140  
   141  	links := []apm.SpanLink{
   142  		{Trace: apm.TraceID{1}, Span: apm.SpanID{1}},
   143  		{Trace: apm.TraceID{2}, Span: apm.SpanID{2}},
   144  	}
   145  
   146  	tx := tracer.StartTransaction("name", "type")
   147  	span := tx.StartSpanOptions("name", "type", apm.SpanOptions{
   148  		Links: links,
   149  	})
   150  
   151  	span.End()
   152  	tx.End()
   153  
   154  	tracer.Flush(nil)
   155  
   156  	payloads := tracer.Payloads()
   157  	require.Len(t, payloads.Spans, 1)
   158  	require.Len(t, payloads.Spans[0].Links, len(links))
   159  
   160  	// Assert span links are identical.
   161  	expectedLinks := []model.SpanLink{
   162  		{TraceID: model.TraceID{1}, SpanID: model.SpanID{1}},
   163  		{TraceID: model.TraceID{2}, SpanID: model.SpanID{2}},
   164  	}
   165  	assert.Equal(t, expectedLinks, payloads.Spans[0].Links)
   166  }
   167  
   168  func TestSpanTiming(t *testing.T) {
   169  	var spanStart, spanEnd time.Time
   170  	txStart := time.Now()
   171  	tx, spans, _ := apmtest.WithTransactionOptions(
   172  		apm.TransactionOptions{Start: txStart},
   173  		func(ctx context.Context) {
   174  			time.Sleep(500 * time.Millisecond)
   175  			span, _ := apm.StartSpan(ctx, "name", "type")
   176  			spanStart = time.Now()
   177  			time.Sleep(500 * time.Millisecond)
   178  			spanEnd = time.Now()
   179  			span.End()
   180  		},
   181  	)
   182  	require.Len(t, spans, 1)
   183  	span := spans[0]
   184  
   185  	assert.InEpsilon(t,
   186  		spanStart.Sub(txStart),
   187  		time.Time(span.Timestamp).Sub(time.Time(tx.Timestamp)),
   188  		0.1, // 10% error
   189  	)
   190  	assert.InEpsilon(t,
   191  		spanEnd.Sub(spanStart)/time.Millisecond,
   192  		span.Duration,
   193  		0.1, // 10% error
   194  	)
   195  }
   196  
   197  func TestSpanType(t *testing.T) {
   198  	spanTypes := []string{"type", "type.subtype", "type.subtype.action", "type.subtype.action.figure"}
   199  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
   200  		for _, spanType := range spanTypes {
   201  			span, _ := apm.StartSpan(ctx, "name", spanType)
   202  			span.End()
   203  		}
   204  	})
   205  	require.Len(t, spans, 4)
   206  
   207  	check := func(s model.Span, spanType, spanSubtype, spanAction string) {
   208  		assert.Equal(t, spanType, s.Type)
   209  		assert.Equal(t, spanSubtype, s.Subtype)
   210  		assert.Equal(t, spanAction, s.Action)
   211  	}
   212  	check(spans[0], "type", "", "")
   213  	check(spans[1], "type", "subtype", "")
   214  	check(spans[2], "type", "subtype", "action")
   215  	check(spans[3], "type", "subtype", "action.figure")
   216  }
   217  
   218  func TestStartExitSpan(t *testing.T) {
   219  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
   220  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{ExitSpan: true})
   221  		span.Duration = 2 * time.Millisecond
   222  		assert.True(t, span.IsExitSpan())
   223  		span.End()
   224  	})
   225  	require.Len(t, spans, 1)
   226  	// When the context's DestinationService is not explicitly set, ending
   227  	// the exit span will assign the value.
   228  	assert.Equal(t, spans[0].Context.Destination.Service.Resource, "type")
   229  
   230  	// When the context's ServiceTarget is not explicitly set, ending
   231  	// the exit span will assign the value.
   232  	assert.Equal(t, spans[0].Context.Service.Target.Type, "type")
   233  
   234  	tracer := apmtest.NewRecordingTracer()
   235  	defer tracer.Close()
   236  
   237  	tx := tracer.StartTransaction("name", "type")
   238  
   239  	span := tx.StartSpanOptions("name", "type", apm.SpanOptions{ExitSpan: true})
   240  	assert.True(t, span.IsExitSpan())
   241  
   242  	// when the parent span is an exit span, children with a different type or
   243  	// subtype should be noops.
   244  	span2 := tx.StartSpan("name", "differenttype", span)
   245  	span2.End()
   246  	assert.True(t, span2.Dropped())
   247  
   248  	// Exit spans MAY have child spans that have the same `type` and `subtype`.
   249  	span3 := tx.StartSpan("name", "type", span)
   250  	span3.End()
   251  	assert.False(t, span3.Dropped())
   252  
   253  	span.End()
   254  
   255  	// Spans should still be marked as an exit span after they've been
   256  	// ended.
   257  	assert.True(t, span.IsExitSpan())
   258  
   259  	// Even ended exit spans MAY have child spans that have the same
   260  	// `type` and `subtype`.
   261  	span4 := tx.StartSpan("name", "type", span)
   262  	span4.End()
   263  	assert.False(t, span4.Dropped())
   264  }
   265  
   266  func TestSpanStackTraceMinDurationSpecialCases(t *testing.T) {
   267  	tracer := apmtest.NewRecordingTracer()
   268  
   269  	// verify that no stacktraces are recorded
   270  	tracer.SetSpanStackTraceMinDuration(-1)
   271  	tx := tracer.StartTransaction("name", "type")
   272  	span := tx.StartSpan("span", "span", nil)
   273  	span.End()
   274  	tx.End()
   275  
   276  	tracer.Flush(nil)
   277  	tracer.Close()
   278  
   279  	spans := tracer.Payloads().Spans
   280  	require.Len(t, spans, 1)
   281  	assert.Len(t, spans[0].Stacktrace, 0)
   282  
   283  	// verify that stacktraces are always recorded
   284  	tracer = apmtest.NewRecordingTracer()
   285  	defer tracer.Close()
   286  	tracer.SetSpanStackTraceMinDuration(0)
   287  	tx = tracer.StartTransaction("name", "type")
   288  	span = tx.StartSpan("span2", "span2", nil)
   289  	span.End()
   290  	tx.End()
   291  
   292  	tracer.Flush(nil)
   293  
   294  	spans = tracer.Payloads().Spans
   295  	require.Len(t, spans, 1)
   296  	assert.NotEmpty(t, spans[0].Stacktrace)
   297  }
   298  
   299  func TestCompressSpanNonSiblings(t *testing.T) {
   300  	// Asserts that non sibling spans are not compressed.
   301  	tracer := apmtest.NewRecordingTracer()
   302  	defer tracer.Close()
   303  
   304  	tracer.SetSpanCompressionEnabled(true)
   305  	// Avoid the spans from being dropped by fast exit spans.
   306  	tracer.SetExitSpanMinDuration(time.Nanosecond)
   307  
   308  	tx := tracer.StartTransaction("name", "type")
   309  	parent := tx.StartSpan("parent", "parent", nil)
   310  
   311  	createSpans := []struct {
   312  		name, typ string
   313  		parent    apm.TraceContext
   314  	}{
   315  		{name: "not compressed", typ: "internal", parent: parent.TraceContext()},
   316  		{name: "not compressed", typ: "internal", parent: tx.TraceContext()},
   317  		{name: "compressed", typ: "internal", parent: parent.TraceContext()},
   318  		{name: "compressed", typ: "internal", parent: parent.TraceContext()},
   319  		{name: "compressed", typ: "different", parent: tx.TraceContext()},
   320  		{name: "compressed", typ: "different", parent: tx.TraceContext()},
   321  	}
   322  	for _, span := range createSpans {
   323  		span := tx.StartSpanOptions(span.name, span.typ, apm.SpanOptions{
   324  			ExitSpan: true, Parent: span.parent,
   325  		})
   326  		span.Duration = time.Millisecond
   327  		span.End()
   328  	}
   329  
   330  	parent.End()
   331  	tx.End()
   332  	tracer.Flush(nil)
   333  
   334  	spans := tracer.Payloads().Spans
   335  	require.Len(t, spans, 5)
   336  
   337  	// First two spans should not have been compressed together.
   338  	require.Nil(t, spans[0].Composite)
   339  	require.Nil(t, spans[1].Composite)
   340  
   341  	assert.NotNil(t, spans[2].Composite)
   342  	assert.Equal(t, 2, spans[2].Composite.Count)
   343  	assert.Equal(t, float64(2), spans[2].Composite.Sum)
   344  	assert.Equal(t, "exact_match", spans[2].Composite.CompressionStrategy)
   345  
   346  	assert.NotNil(t, spans[3].Composite)
   347  	assert.Equal(t, 2, spans[3].Composite.Count)
   348  	assert.Equal(t, float64(2), spans[3].Composite.Sum)
   349  	assert.Equal(t, "exact_match", spans[3].Composite.CompressionStrategy)
   350  }
   351  
   352  func TestCompressSpanExactMatch(t *testing.T) {
   353  	// Aserts that that span compression works on compressable spans with
   354  	// "exact_match" strategy.
   355  	tests := []struct {
   356  		setup              func(t *testing.T) func()
   357  		assertFunc         func(t *testing.T, tx model.Transaction, spans []model.Span)
   358  		name               string
   359  		compressionEnabled bool
   360  	}{
   361  		// |______________transaction (095b51e1b6ca784c) - 2.0013ms_______________|
   362  		// m
   363  		// m
   364  		// m
   365  		// m
   366  		// m
   367  		// m
   368  		// m
   369  		// m
   370  		// m
   371  		// m
   372  		// |___________________mysql SELECT * FROM users - 2ms____________________|
   373  		//                                                                        r
   374  		//                                                                        i
   375  		//                                                                        r
   376  		{
   377  			name:               "CompressFalse",
   378  			compressionEnabled: false,
   379  			assertFunc: func(t *testing.T, tx model.Transaction, spans []model.Span) {
   380  				require.NotEmpty(t, tx)
   381  				require.Equal(t, 14, len(spans))
   382  				for _, span := range spans {
   383  					require.Nil(t, span.Composite)
   384  				}
   385  			},
   386  		},
   387  		// |______________transaction (7d3254511f02b26b) - 2.0013ms_______________|
   388  		// 10
   389  		//  |___________________mysql SELECT * FROM users - 2ms___________________|
   390  		//                                                                        r
   391  		//                                                                        i
   392  		//                                                                        r
   393  		{
   394  			name:               "CompressTrueSettingTweak",
   395  			compressionEnabled: true,
   396  			setup: func(*testing.T) func() {
   397  				// This setting
   398  				envVarName := "ELASTIC_APM_SPAN_COMPRESSION_EXACT_MATCH_MAX_DURATION"
   399  				og := os.Getenv(envVarName)
   400  				os.Setenv(envVarName, "1ms")
   401  				return func() { os.Setenv(envVarName, og) }
   402  			},
   403  			assertFunc: func(t *testing.T, tx model.Transaction, spans []model.Span) {
   404  				require.NotNil(t, tx)
   405  				require.Equal(t, 5, len(spans))
   406  				composite := spans[0]
   407  				require.NotNil(t, composite.Composite)
   408  				assert.Equal(t, "SELECT * FROM users", composite.Name)
   409  				assert.Equal(t, "exact_match", composite.Composite.CompressionStrategy)
   410  				assert.Equal(t, composite.Composite.Count, 10)
   411  				assert.Equal(t, 0.001, composite.Composite.Sum)
   412  				assert.Equal(t, 0.001, composite.Duration)
   413  
   414  				for _, span := range spans[1:] {
   415  					require.Nil(t, span.Composite)
   416  				}
   417  			},
   418  		},
   419  		// |______________transaction (5797fe58c6ccce29) - 2.0013ms_______________|
   420  		// |_____________________11 Calls to mysql - 2.001ms______________________|
   421  		//                                                                        r
   422  		//                                                                        i
   423  		//                                                                        r
   424  		{
   425  			name:               "CompressSpanCount4",
   426  			compressionEnabled: true,
   427  			assertFunc: func(t *testing.T, tx model.Transaction, spans []model.Span) {
   428  				require.NotEmpty(t, tx)
   429  				var composite = spans[0]
   430  				assert.Equal(t, composite.Context.Destination.Service.Resource, "mysql")
   431  
   432  				require.NotNil(t, composite.Composite)
   433  				assert.Equal(t, "SELECT * FROM users", composite.Name)
   434  				assert.Equal(t, composite.Composite.Count, 11)
   435  				assert.Equal(t, "exact_match", composite.Composite.CompressionStrategy)
   436  				// Sum should be at least the time that each span ran for. The
   437  				// model time is in Milliseconds and the span duration should be
   438  				// at least 2 Milliseconds
   439  				assert.Equal(t, int(composite.Composite.Sum), 2)
   440  				assert.Equal(t, int(composite.Duration), 2)
   441  
   442  				for _, span := range spans {
   443  					if span.Type == "mysql" {
   444  						continue
   445  					}
   446  					assert.Nil(t, span.Composite)
   447  				}
   448  			},
   449  		},
   450  	}
   451  	for _, test := range tests {
   452  		t.Run(test.name, func(t *testing.T) {
   453  			if test.setup != nil {
   454  				defer test.setup(t)()
   455  			}
   456  
   457  			tracer := apmtest.NewRecordingTracer()
   458  			tracer.SetExitSpanMinDuration(time.Nanosecond)
   459  			defer tracer.Close()
   460  			tracer.SetSpanCompressionEnabled(test.compressionEnabled)
   461  
   462  			// When compression is enabled:
   463  			// Compress 10 spans into 1 and add another span with a different type
   464  			// [                    Transaction                    ]
   465  			//  [ mysql (11) ] [ request ] [ internal ] [ request ]
   466  			//
   467  			txStart := time.Now()
   468  			tx := tracer.StartTransactionOptions("name", "type",
   469  				apm.TransactionOptions{Start: txStart},
   470  			)
   471  			currentTime := txStart
   472  			for i := 0; i < 10; i++ {
   473  				span := tx.StartSpanOptions("SELECT * FROM users", "mysql", apm.SpanOptions{
   474  					ExitSpan: true, Start: currentTime,
   475  				})
   476  				span.Duration = 100 * time.Nanosecond
   477  				currentTime = currentTime.Add(span.Duration)
   478  				span.End()
   479  			}
   480  			// Compressed when the exact_match threshold is >= 2ms.
   481  			{
   482  				span := tx.StartSpanOptions("SELECT * FROM users", "mysql", apm.SpanOptions{
   483  					ExitSpan: true, Start: currentTime,
   484  				})
   485  				span.Duration = 2 * time.Millisecond
   486  				currentTime = currentTime.Add(span.Duration)
   487  				span.End()
   488  			}
   489  
   490  			// None of these should be added to the composite.
   491  			{
   492  				span := tx.StartSpanOptions("GET /", "request", apm.SpanOptions{
   493  					ExitSpan: true, Start: currentTime,
   494  				})
   495  				span.Duration = 100 * time.Nanosecond
   496  				currentTime = currentTime.Add(span.Duration)
   497  				span.End()
   498  			}
   499  			{
   500  				// Not an exit span, should not be compressed
   501  				span := tx.StartSpanOptions("calculate complex", "internal", apm.SpanOptions{
   502  					Start: currentTime,
   503  				})
   504  				span.Duration = 100 * time.Nanosecond
   505  				currentTime = currentTime.Add(span.Duration)
   506  				span.End()
   507  			}
   508  			{
   509  				// Exit span, this is a good candidate to be compressed, but
   510  				// since it can't be compressed with the last request type ("internal")
   511  				span := tx.StartSpanOptions("GET /", "request", apm.SpanOptions{
   512  					ExitSpan: true, Start: currentTime,
   513  				})
   514  				span.Duration = 100 * time.Nanosecond
   515  				currentTime = currentTime.Add(span.Duration)
   516  				span.End()
   517  			}
   518  			tx.Duration = currentTime.Sub(txStart)
   519  			tx.End()
   520  			tracer.Flush(nil)
   521  
   522  			transaction := tracer.Payloads().Transactions[0]
   523  			spans := tracer.Payloads().Spans
   524  			defer func() {
   525  				if t.Failed() {
   526  					apmtest.WriteTraceWaterfall(os.Stdout, transaction, spans)
   527  					apmtest.WriteTraceTable(os.Stdout, transaction, spans)
   528  				}
   529  			}()
   530  
   531  			if test.assertFunc != nil {
   532  				test.assertFunc(t, transaction, spans)
   533  			}
   534  		})
   535  	}
   536  }
   537  
   538  func TestCompressSpanName(t *testing.T) {
   539  	type testcase struct {
   540  		name              string
   541  		serviceTargetName string
   542  		serviceTargetType string
   543  		expectedName      string
   544  	}
   545  	testcases := []testcase{{
   546  		name:         "unknown",
   547  		expectedName: "Calls to unknown",
   548  	}, {
   549  		name:              "unknown type",
   550  		serviceTargetName: "foo",
   551  		// service target type is inferred so the expected name is type/name
   552  		expectedName: "Calls to request/foo",
   553  	}, {
   554  		name:              "unknown name",
   555  		serviceTargetType: "bar",
   556  		expectedName:      "Calls to bar",
   557  	}, {
   558  		name:              "known",
   559  		serviceTargetName: "foo",
   560  		serviceTargetType: "bar",
   561  		expectedName:      "Calls to bar/foo",
   562  	}}
   563  	for _, tc := range testcases {
   564  		t.Run(tc.name, func(t *testing.T) {
   565  			tracer := apmtest.NewRecordingTracer()
   566  			t.Cleanup(tracer.Close)
   567  
   568  			tracer.SetSpanCompressionEnabled(true)
   569  			tracer.SetSpanCompressionSameKindMaxDuration(5 * time.Second)
   570  			// Don't drop fast exit spans.
   571  			tracer.SetExitSpanMinDuration(0)
   572  
   573  			txStart := time.Now()
   574  			tx := tracer.StartTransactionOptions("name", "type",
   575  				apm.TransactionOptions{
   576  					Start: txStart,
   577  				},
   578  			)
   579  			currentTime := txStart
   580  
   581  			// These should be compressed into 1 since they meet the compression
   582  			// criteria.
   583  			path := []string{"/a", "/b", "/c", "/d", "/e"}
   584  			for i := 0; i < len(path); i++ {
   585  				span := tx.StartSpanOptions(fmt.Sprint("GET ", path[i]), "request", apm.SpanOptions{
   586  					ExitSpan: true, Start: currentTime,
   587  				})
   588  				span.Duration = 100 * time.Nanosecond
   589  				currentTime = currentTime.Add(span.Duration)
   590  				span.Context.SetServiceTarget(apm.ServiceTargetSpanContext{
   591  					Type: tc.serviceTargetType,
   592  					Name: tc.serviceTargetName,
   593  				})
   594  				span.End()
   595  			}
   596  
   597  			tx.Duration = currentTime.Sub(txStart)
   598  			tx.End()
   599  			tracer.Flush(nil)
   600  
   601  			transaction := tracer.Payloads().Transactions[0]
   602  			spans := tracer.Payloads().Spans
   603  
   604  			t.Cleanup(func() {
   605  				if t.Failed() {
   606  					apmtest.WriteTraceWaterfall(os.Stdout, transaction, spans)
   607  					apmtest.WriteTraceTable(os.Stdout, transaction, spans)
   608  				}
   609  			})
   610  
   611  			require.Equal(t, 1, len(spans))
   612  			requestSpan := spans[0]
   613  			assert.NotNil(t, requestSpan.Composite)
   614  			assert.Equal(t, 5, requestSpan.Composite.Count)
   615  			assert.Equal(t, tc.expectedName, requestSpan.Name)
   616  			assert.Equal(t, "same_kind", requestSpan.Composite.CompressionStrategy)
   617  		})
   618  	}
   619  }
   620  
   621  func TestCompressSpanSameKind(t *testing.T) {
   622  	// Aserts that that span compression works on compressable spans with
   623  	// "same_kind" strategy, and that different span types are not compressed.
   624  	testCase := func(tracer *apmtest.RecordingTracer) (model.Transaction, []model.Span, func()) {
   625  		txStart := time.Now()
   626  		tx := tracer.StartTransactionOptions("name", "type",
   627  			apm.TransactionOptions{Start: txStart},
   628  		)
   629  		currentTime := txStart
   630  
   631  		// Span is compressable, but cannot be compressed since the next span
   632  		// is not the same kind. It's published.
   633  		{
   634  			span := tx.StartSpanOptions("SELECT * FROM users", "mysql", apm.SpanOptions{
   635  				ExitSpan: true, Start: currentTime,
   636  			})
   637  			span.Duration = 100 * time.Nanosecond
   638  			currentTime = currentTime.Add(span.Duration)
   639  			span.End()
   640  		}
   641  		// These should be compressed into 1 since they meet the compression
   642  		// criteria.
   643  		path := []string{"/a", "/b", "/c", "/d", "/e"}
   644  		for i := 0; i < len(path); i++ {
   645  			span := tx.StartSpanOptions(fmt.Sprint("GET ", path[i]), "request", apm.SpanOptions{
   646  				ExitSpan: true, Start: currentTime,
   647  			})
   648  			span.Duration = 100 * time.Nanosecond
   649  			currentTime = currentTime.Add(span.Duration)
   650  			span.End()
   651  		}
   652  		// This span exceeds the default threshold (5ms) and won't be compressed.
   653  		{
   654  			span := tx.StartSpanOptions("GET /f", "request", apm.SpanOptions{
   655  				ExitSpan: true, Start: currentTime,
   656  			})
   657  			span.Duration = 6 * time.Millisecond
   658  			currentTime = currentTime.Add(span.Duration)
   659  			span.End()
   660  		}
   661  		// Span is compressable and the next span is the same kind, but cannot be compressed
   662  		// since the service target fields are different (inferred by the db instance).
   663  		{
   664  			span := tx.StartSpanOptions("SELECT * FROM users", "mysql", apm.SpanOptions{
   665  				ExitSpan: true, Start: currentTime,
   666  			})
   667  			span.Duration = 100 * time.Nanosecond
   668  			span.Context.SetServiceTarget(apm.ServiceTargetSpanContext{
   669  				Type: "db",
   670  				Name: "foo",
   671  			})
   672  			currentTime = currentTime.Add(span.Duration)
   673  			span.End()
   674  		}
   675  		{
   676  			span := tx.StartSpanOptions("SELECT * FROM users", "mysql", apm.SpanOptions{
   677  				ExitSpan: true, Start: currentTime,
   678  			})
   679  			span.Duration = 100 * time.Nanosecond
   680  			span.Context.SetServiceTarget(apm.ServiceTargetSpanContext{
   681  				Type: "db",
   682  				Name: "bar",
   683  			})
   684  			currentTime = currentTime.Add(span.Duration)
   685  			span.End()
   686  		}
   687  		tx.Duration = currentTime.Sub(txStart)
   688  		tx.End()
   689  		tracer.Flush(nil)
   690  
   691  		transaction := tracer.Payloads().Transactions[0]
   692  		spans := tracer.Payloads().Spans
   693  		debugFunc := func() {
   694  			if t.Failed() {
   695  				apmtest.WriteTraceWaterfall(os.Stdout, transaction, spans)
   696  				apmtest.WriteTraceTable(os.Stdout, transaction, spans)
   697  			}
   698  		}
   699  		return transaction, spans, debugFunc
   700  	}
   701  
   702  	t.Run("DefaultDisabled", func(t *testing.T) {
   703  		// By default same kind compression is disabled thus count will be 7.
   704  		tracer := apmtest.NewRecordingTracer()
   705  		defer tracer.Close()
   706  		tracer.SetSpanCompressionEnabled(true)
   707  		// Don't drop fast exit spans.
   708  		tracer.SetExitSpanMinDuration(0)
   709  
   710  		_, spans, debugFunc := testCase(tracer)
   711  		defer debugFunc()
   712  
   713  		require.Equal(t, 9, len(spans))
   714  		mysqlSpan := spans[0]
   715  		assert.Equal(t, "mysql", mysqlSpan.Context.Destination.Service.Resource)
   716  		assert.Nil(t, mysqlSpan.Composite)
   717  
   718  		requestSpan := spans[1]
   719  		assert.Equal(t, "request", requestSpan.Context.Destination.Service.Resource)
   720  		require.Nil(t, requestSpan.Composite)
   721  	})
   722  
   723  	t.Run("10msThreshold", func(t *testing.T) {
   724  		// With this threshold the composite count will be 6.
   725  		os.Setenv("ELASTIC_APM_SPAN_COMPRESSION_SAME_KIND_MAX_DURATION", "10ms")
   726  		defer os.Unsetenv("ELASTIC_APM_SPAN_COMPRESSION_SAME_KIND_MAX_DURATION")
   727  
   728  		tracer := apmtest.NewRecordingTracer()
   729  		defer tracer.Close()
   730  		tracer.SetSpanCompressionEnabled(true)
   731  		// Don't drop fast exit spans.
   732  		tracer.SetExitSpanMinDuration(0)
   733  
   734  		_, spans, debugFunc := testCase(tracer)
   735  		defer debugFunc()
   736  
   737  		mysqlSpan := spans[0]
   738  		assert.Equal(t, mysqlSpan.Context.Destination.Service.Resource, "mysql")
   739  		assert.Nil(t, mysqlSpan.Composite)
   740  
   741  		requestSpan := spans[1]
   742  		assert.Equal(t, requestSpan.Context.Destination.Service.Resource, "request")
   743  		assert.NotNil(t, requestSpan.Composite)
   744  		assert.Equal(t, 6, requestSpan.Composite.Count)
   745  		assert.Equal(t, "Calls to request", requestSpan.Name)
   746  		assert.Equal(t, "same_kind", requestSpan.Composite.CompressionStrategy)
   747  		// Check that the aggregate sum is at least the duration of the time we
   748  		// we waited for.
   749  		assert.Greater(t, requestSpan.Composite.Sum, float64(5*100/time.Millisecond))
   750  
   751  		// Check that the total composite span duration is at least 5 milliseconds.
   752  		assert.Greater(t, requestSpan.Duration, float64(5*100/time.Millisecond))
   753  	})
   754  	t.Run("DefaultThresholdDropFastExitSpan", func(t *testing.T) {
   755  		tracer := apmtest.NewRecordingTracer()
   756  		defer tracer.Close()
   757  		tracer.SetSpanCompressionEnabled(true)
   758  
   759  		tx, spans, debugFunc := testCase(tracer)
   760  		defer debugFunc()
   761  
   762  		// drops all spans except the last request span.
   763  		require.Equal(t, 1, len(spans))
   764  		// Collects statistics about the dropped spans (request and mysql).
   765  		require.Equal(t, 4, len(tx.DroppedSpansStats))
   766  	})
   767  }
   768  
   769  func TestCompressSpanSameKindParentSpan(t *testing.T) {
   770  	// This test asserts the span compression works when the spans are children
   771  	// of another span.
   772  	tracer := apmtest.NewRecordingTracer()
   773  	tracer.SetSpanCompressionEnabled(true)
   774  	tracer.SetExitSpanMinDuration(0)
   775  	tracer.SetSpanCompressionSameKindMaxDuration(5 * time.Millisecond)
   776  
   777  	// This test case covers spans that have other spans as parents.
   778  	// |_______________transaction (6b1e4866252dea6f) - 1.45ms________________|
   779  	// |__internal internal op - 700µs___|
   780  	//      |request GET /r|
   781  	//       |request G|
   782  	//                                    |___internal another op - 750µs____|
   783  	//                                         |2 Calls to re|
   784  	txStart := time.Now()
   785  	tx := tracer.StartTransactionOptions("name", "type",
   786  		apm.TransactionOptions{Start: txStart},
   787  	)
   788  
   789  	ctx := apm.ContextWithTransaction(context.Background(), tx)
   790  	currentTime := txStart
   791  	{
   792  		// Doesn't compress any spans since none meet the necessary conditions
   793  		// the "request" type are both the same type but the parent
   794  		parent, ctx := apm.StartSpanOptions(ctx, "internal op", "internal", apm.SpanOptions{
   795  			Start: currentTime,
   796  		})
   797  		// Have span propagate context downstream, this should not allow for
   798  		// compression
   799  		child, ctx := apm.StartSpanOptions(ctx, "GET /resource", "request", apm.SpanOptions{
   800  			Start: currentTime.Add(100 * time.Microsecond),
   801  		})
   802  
   803  		grandChild, _ := apm.StartSpanOptions(ctx, "GET /different", "request", apm.SpanOptions{
   804  			ExitSpan: true,
   805  			Start:    currentTime.Add(120 * time.Microsecond),
   806  		})
   807  
   808  		grandChild.Duration = 200 * time.Microsecond
   809  		grandChild.End()
   810  
   811  		child.Duration = 300 * time.Microsecond
   812  		child.End()
   813  
   814  		parent.Duration = 700 * time.Microsecond
   815  		currentTime = currentTime.Add(parent.Duration)
   816  		parent.End()
   817  	}
   818  	{
   819  		// Compresses the last two spans together since they are  both exit
   820  		// spans, same "request" type, don't propagate ctx and succeed.
   821  		parent, ctx := apm.StartSpanOptions(ctx, "another op", "internal", apm.SpanOptions{
   822  			Start: currentTime.Add(50 * time.Microsecond),
   823  		})
   824  		child, _ := apm.StartSpanOptions(ctx, "GET /res", "request", apm.SpanOptions{
   825  			ExitSpan: true,
   826  			Start:    currentTime.Add(120 * time.Microsecond),
   827  		})
   828  
   829  		otherChild, _ := apm.StartSpanOptions(ctx, "GET /diff", "request", apm.SpanOptions{
   830  			ExitSpan: true,
   831  			Start:    currentTime.Add(150 * time.Microsecond),
   832  		})
   833  
   834  		otherChild.Duration = 250 * time.Microsecond
   835  		otherChild.End()
   836  
   837  		child.Duration = 300 * time.Microsecond
   838  		child.End()
   839  
   840  		parent.Duration = 750 * time.Microsecond
   841  		currentTime = currentTime.Add(parent.Duration)
   842  		parent.End()
   843  	}
   844  
   845  	tx.Duration = currentTime.Sub(txStart)
   846  	tx.End()
   847  	tracer.Flush(nil)
   848  
   849  	transaction := tracer.Payloads().Transactions[0]
   850  	spans := tracer.Payloads().Spans
   851  
   852  	defer func() {
   853  		if t.Failed() {
   854  			apmtest.WriteTraceTable(os.Stdout, transaction, spans)
   855  			apmtest.WriteTraceWaterfall(os.Stdout, transaction, spans)
   856  		}
   857  	}()
   858  	require.NotNil(t, transaction)
   859  	assert.Equal(t, 5, len(spans))
   860  
   861  	compositeSpan := spans[3]
   862  	compositeParent := spans[4]
   863  	require.NotNil(t, compositeSpan)
   864  	require.NotNil(t, compositeSpan.Composite)
   865  	assert.Equal(t, "Calls to request", compositeSpan.Name)
   866  	assert.Equal(t, "request", compositeSpan.Type)
   867  	assert.Equal(t, "internal", compositeParent.Type)
   868  	assert.Equal(t, compositeSpan.Composite.Count, 2)
   869  	assert.Equal(t, compositeSpan.ParentID, compositeParent.ID)
   870  	assert.GreaterOrEqual(t, compositeParent.Duration, compositeSpan.Duration)
   871  }
   872  
   873  func TestCompressSpanSameKindParentSpanContext(t *testing.T) {
   874  	// This test ensures that the compression also works when the s.Parent is
   875  	// set (via the context.Context).
   876  	// |________________transaction (6df3948c6eff7b57) - 15ms_________________|
   877  	// |_____________________internal parent - 14ms______________________|
   878  	// 	   |_3 db - 3ms__|
   879  	// 							|_internal algorithm - 6ms__|
   880  	// 								|2 Calls to client |
   881  	// 											   |inte|
   882  	tracer := apmtest.NewRecordingTracer()
   883  	tracer.SetSpanCompressionEnabled(true)
   884  	tracer.SetExitSpanMinDuration(0)
   885  	tracer.SetSpanCompressionSameKindMaxDuration(5 * time.Millisecond)
   886  
   887  	txStart := time.Now()
   888  	tx := tracer.StartTransactionOptions("name", "type",
   889  		apm.TransactionOptions{Start: txStart},
   890  	)
   891  
   892  	ctx := apm.ContextWithTransaction(context.Background(), tx)
   893  	parentStart := txStart.Add(time.Millisecond)
   894  	parent, ctx := apm.StartSpanOptions(ctx, "parent", "internal", apm.SpanOptions{
   895  		Start: parentStart,
   896  	})
   897  
   898  	// These spans are all compressed into a composite.
   899  	childrenStart := parentStart.Add(2 * time.Millisecond)
   900  	for i := 0; i < 3; i++ {
   901  		span, _ := apm.StartSpanOptions(ctx, "db", "redis", apm.SpanOptions{
   902  			ExitSpan: true,
   903  			Start:    childrenStart,
   904  		})
   905  		childrenStart = childrenStart.Add(time.Millisecond)
   906  		span.Duration = time.Millisecond
   907  		span.End()
   908  	}
   909  
   910  	// We create a nother "internal" type span from which 3 children (below)
   911  	// are created. one of them
   912  	testSpans := []struct {
   913  		name     string
   914  		typ      string
   915  		duration time.Duration
   916  	}{
   917  		{name: "GET /some", typ: "client", duration: time.Millisecond},
   918  		{name: "GET /resource", typ: "client", duration: 2 * time.Millisecond},
   919  		{name: "compute something", typ: "internal", duration: time.Millisecond},
   920  	}
   921  
   922  	subParent, ctx := apm.StartSpanOptions(ctx, "algorithm", "internal", apm.SpanOptions{
   923  		Start: childrenStart.Add(time.Millisecond),
   924  	})
   925  	childrenStart = childrenStart.Add(time.Millisecond)
   926  	for _, childCfg := range testSpans {
   927  		child, _ := apm.StartSpanOptions(ctx, childCfg.name, childCfg.typ, apm.SpanOptions{
   928  			ExitSpan: true,
   929  			Start:    childrenStart.Add(childCfg.duration),
   930  		})
   931  		childrenStart = childrenStart.Add(childCfg.duration)
   932  		child.Duration = childCfg.duration
   933  		child.End()
   934  	}
   935  	childrenStart = childrenStart.Add(time.Millisecond)
   936  	subParent.Duration = 6 * time.Millisecond
   937  	subParent.End()
   938  
   939  	parent.Duration = childrenStart.Add(2 * time.Millisecond).Sub(txStart)
   940  	parent.End()
   941  	tx.Duration = 15 * time.Millisecond
   942  	tx.End()
   943  
   944  	tracer.Flush(nil)
   945  
   946  	transaction := tracer.Payloads().Transactions[0]
   947  	spans := tracer.Payloads().Spans
   948  
   949  	defer func() {
   950  		if t.Failed() {
   951  			apmtest.WriteTraceTable(os.Stdout, transaction, spans)
   952  			apmtest.WriteTraceWaterfall(os.Stdout, transaction, spans)
   953  		}
   954  	}()
   955  	require.NotNil(t, transaction)
   956  	assert.Equal(t, 5, len(spans))
   957  
   958  	sort.SliceStable(spans, func(i, j int) bool {
   959  		return time.Time(spans[i].Timestamp).Before(time.Time(spans[j].Timestamp))
   960  	})
   961  
   962  	redisSpan := spans[1]
   963  	require.NotNil(t, redisSpan.Composite)
   964  	assert.Equal(t, "db", redisSpan.Name)
   965  	assert.Equal(t, 3, redisSpan.Composite.Count)
   966  	assert.Equal(t, float64(3), redisSpan.Composite.Sum)
   967  	assert.Equal(t, "exact_match", redisSpan.Composite.CompressionStrategy)
   968  
   969  	clientSpan := spans[3]
   970  	require.NotNil(t, clientSpan.Composite)
   971  	assert.Equal(t, "Calls to client", clientSpan.Name)
   972  	assert.Equal(t, clientSpan.ParentID, spans[2].ID)
   973  	assert.Equal(t, 2, clientSpan.Composite.Count)
   974  	assert.Equal(t, float64(3), clientSpan.Composite.Sum)
   975  	assert.Equal(t, "same_kind", clientSpan.Composite.CompressionStrategy)
   976  }
   977  
   978  func TestCompressSpanSameKindConcurrent(t *testing.T) {
   979  	// This test verifies there aren't any deadlocks on calling
   980  	// span.End(), Parent.End() and tx.End().
   981  	// Additionally, ensures that we're not leaking or losing any
   982  	// spans on parents and transaction being ended early.
   983  	tracer := apmtest.NewRecordingTracer()
   984  	tracer.SetSpanCompressionEnabled(true)
   985  	tracer.SetExitSpanMinDuration(0)
   986  
   987  	tx := tracer.StartTransaction("name", "type")
   988  	ctx := apm.ContextWithTransaction(context.Background(), tx)
   989  	parent, ctx := apm.StartSpan(ctx, "parent", "internal")
   990  
   991  	var wg sync.WaitGroup
   992  	count := 100
   993  	wg.Add(count)
   994  	spanStarted := make(chan struct{})
   995  	for i := 0; i < count; i++ {
   996  		go func(i int) {
   997  			child, _ := apm.StartSpanOptions(ctx, fmt.Sprint(i), "request", apm.SpanOptions{
   998  				ExitSpan: true,
   999  			})
  1000  			spanStarted <- struct{}{}
  1001  			child.End()
  1002  			wg.Done()
  1003  		}(i)
  1004  	}
  1005  
  1006  	var received int
  1007  	for range spanStarted {
  1008  		received++
  1009  		if received >= 30 {
  1010  			tx.End()
  1011  		}
  1012  		if received >= 50 {
  1013  			parent.End()
  1014  		}
  1015  		if received == count {
  1016  			close(spanStarted)
  1017  		}
  1018  	}
  1019  	// Wait until all the spans have ended.
  1020  	wg.Wait()
  1021  
  1022  	tracer.Flush(nil)
  1023  	payloads := tracer.Payloads()
  1024  	require.Len(t, payloads.Transactions, 1)
  1025  	defer func() {
  1026  		if t.Failed() {
  1027  			apmtest.WriteTraceTable(os.Stdout, payloads.Transactions[0], payloads.Spans)
  1028  			apmtest.WriteTraceWaterfall(os.Stdout, payloads.Transactions[0], payloads.Spans)
  1029  		}
  1030  	}()
  1031  
  1032  	var spanCount int
  1033  	for _, span := range payloads.Spans {
  1034  		if span.Composite != nil {
  1035  			// The real span count is the composite count.
  1036  			spanCount += span.Composite.Count
  1037  			continue
  1038  		}
  1039  		// If it's a normal span, then increment by 1.
  1040  		spanCount++
  1041  	}
  1042  
  1043  	// Asserts that the total spancount is 101, (100 generated spans + parent).
  1044  	assert.Equal(t, 101, spanCount)
  1045  }
  1046  
  1047  func TestCompressSpanPrematureEnd(t *testing.T) {
  1048  	// This test cases assert that the cached spans are sent when the span or
  1049  	// tx that holds their cache is ended and the cache isn't lost.
  1050  	type expect struct {
  1051  		compressionStrategy string
  1052  		compositeSum        float64
  1053  		spanCount           int
  1054  		compositeCount      int
  1055  	}
  1056  	assertResult := func(t *testing.T, tx model.Transaction, spans []model.Span, expect expect) {
  1057  		defer func() {
  1058  			if t.Failed() {
  1059  				apmtest.WriteTraceTable(os.Stdout, tx, spans)
  1060  				apmtest.WriteTraceWaterfall(os.Stdout, tx, spans)
  1061  			}
  1062  		}()
  1063  		assert.Equal(t, expect.spanCount, len(spans))
  1064  		var composite *model.CompositeSpan
  1065  		for _, span := range spans {
  1066  			if span.Composite != nil {
  1067  				assert.Equal(t, expect.compositeCount, span.Composite.Count)
  1068  				assert.Equal(t, expect.compressionStrategy, span.Composite.CompressionStrategy)
  1069  				assert.Equal(t, expect.compositeSum, span.Composite.Sum)
  1070  				composite = span.Composite
  1071  			}
  1072  		}
  1073  		if expect.compositeCount > 0 {
  1074  			require.NotNil(t, composite)
  1075  		}
  1076  	}
  1077  
  1078  	testCases := []struct {
  1079  		name                string
  1080  		exitSpanMinDuration time.Duration
  1081  		expect              expect
  1082  		droppedSpansStats   int
  1083  	}{
  1084  		{
  1085  			name: "NoDropExitSpans",
  1086  			expect: expect{
  1087  				spanCount:           3,
  1088  				compositeCount:      3,
  1089  				compressionStrategy: "same_kind",
  1090  				compositeSum:        1.5,
  1091  			},
  1092  		},
  1093  		{
  1094  			name:                "DropExitSpans",
  1095  			exitSpanMinDuration: time.Millisecond,
  1096  			droppedSpansStats:   1,
  1097  			expect: expect{
  1098  				spanCount:           2,
  1099  				compositeCount:      3,
  1100  				compressionStrategy: "same_kind",
  1101  				compositeSum:        1.5,
  1102  			},
  1103  		},
  1104  	}
  1105  
  1106  	// 1. The parent ends before they do.
  1107  	// The parent holds the compression cache in this test case.
  1108  	// |      tx      |
  1109  	// |  parent |        <--- The parent ends before the children ends.
  1110  	// | child |          <--- compressed
  1111  	// |  child |         <--- compressed
  1112  	// |  child |         <--- compressed
  1113  	// |    child  |      <--- NOT compressed
  1114  	// The expected result are 3 spans, the cache is invalidated and the span
  1115  	// ended after the parent ends.
  1116  	//
  1117  	// When drop fast exit spans is enabled, with 1ms min duration, the expected
  1118  	// span count is 2 (parent and the a composite which duration exceeds 1ms).
  1119  	// |      tx      |
  1120  	// |  parent |        <--- The parent ends before the children ends.
  1121  	// | child |          <--- compressed
  1122  	// |  child |         <--- compressed
  1123  	// |  child |         <--- compressed
  1124  	// |    child  |      <--- discarded since its duration is < than min exit.
  1125  	for _, test := range testCases {
  1126  		t.Run("ParentContext/"+test.name, func(t *testing.T) {
  1127  			tracer := apmtest.NewRecordingTracer()
  1128  			defer tracer.Close()
  1129  			tracer.SetSpanCompressionEnabled(true)
  1130  			tracer.SetExitSpanMinDuration(test.exitSpanMinDuration)
  1131  			tracer.SetSpanCompressionSameKindMaxDuration(5 * time.Millisecond)
  1132  
  1133  			txStart := time.Now()
  1134  			tx := tracer.StartTransaction("name", "type")
  1135  			ctx := apm.ContextWithTransaction(context.Background(), tx)
  1136  			currentTime := time.Now()
  1137  			parent, ctx := apm.StartSpanOptions(ctx, "parent", "internal", apm.SpanOptions{
  1138  				Start: currentTime,
  1139  			})
  1140  			for i := 0; i < 4; i++ {
  1141  				child, _ := apm.StartSpanOptions(ctx, fmt.Sprint(i), "type", apm.SpanOptions{
  1142  					Parent:   parent.TraceContext(),
  1143  					ExitSpan: true,
  1144  					Start:    currentTime,
  1145  				})
  1146  				child.Duration = 500 * time.Microsecond
  1147  				currentTime = currentTime.Add(time.Millisecond)
  1148  				child.End()
  1149  				if i == 2 {
  1150  					parent.Duration = 2 * time.Millisecond
  1151  					parent.End()
  1152  				}
  1153  			}
  1154  			tx.Duration = currentTime.Sub(txStart)
  1155  			tx.End()
  1156  			tracer.Flush(nil)
  1157  
  1158  			assertResult(t,
  1159  				tracer.Payloads().Transactions[0], tracer.Payloads().Spans, test.expect,
  1160  			)
  1161  
  1162  			assert.Len(t,
  1163  				tracer.Payloads().Transactions[0].DroppedSpansStats,
  1164  				test.droppedSpansStats,
  1165  			)
  1166  		})
  1167  	}
  1168  
  1169  	// 2. The tx ends before the parent ends.
  1170  	// The tx holds the compression cache in this test case.
  1171  	// |    tx   |          <--- The TX ends before parent.
  1172  	// |   parent  |
  1173  	// | child |            <--- compressed
  1174  	// |  child |           <--- compressed
  1175  	// The expected result are 3 spans, the cache is invalidated and the span
  1176  	// ended after the parent ends.
  1177  	t.Run("TxEndBefore", func(t *testing.T) {
  1178  		tracer := apmtest.NewRecordingTracer()
  1179  		defer tracer.Close()
  1180  		tracer.SetSpanCompressionEnabled(true)
  1181  		tracer.SetExitSpanMinDuration(time.Nanosecond)
  1182  		tracer.SetSpanCompressionSameKindMaxDuration(5 * time.Millisecond)
  1183  
  1184  		tx := tracer.StartTransaction("name", "type")
  1185  		ctx := apm.ContextWithTransaction(context.Background(), tx)
  1186  
  1187  		parent, ctx := apm.StartSpan(ctx, "parent", "internal")
  1188  		for i := 0; i < 2; i++ {
  1189  			child, _ := apm.StartSpanOptions(ctx, fmt.Sprint(i), "type", apm.SpanOptions{
  1190  				ExitSpan: true,
  1191  			})
  1192  			child.Duration = time.Microsecond
  1193  			child.End()
  1194  		}
  1195  		tx.End()
  1196  		parent.End()
  1197  		tracer.Flush(nil)
  1198  		assertResult(t, tracer.Payloads().Transactions[0], tracer.Payloads().Spans, expect{
  1199  			spanCount:           2,
  1200  			compositeCount:      2,
  1201  			compressionStrategy: "same_kind",
  1202  			compositeSum:        0.002,
  1203  		})
  1204  	})
  1205  
  1206  	// 2. The parent ends before the last of the children span are finished.
  1207  	// The tx holds the compression cache in this test case.
  1208  	// |      tx      |
  1209  	// |  parent  |         <--- The parent ends before the last child ends.
  1210  	// | child |           <--- compressed
  1211  	// |  child |          <--- compressed
  1212  	// |    child  |       <--- NOT compressed
  1213  	t.Run("ParentFromTx", func(t *testing.T) {
  1214  		tracer := apmtest.NewRecordingTracer()
  1215  		defer tracer.Close()
  1216  		tracer.SetSpanCompressionEnabled(true)
  1217  		tracer.SetExitSpanMinDuration(time.Nanosecond)
  1218  		tracer.SetSpanCompressionSameKindMaxDuration(5 * time.Millisecond)
  1219  
  1220  		tx := tracer.StartTransaction("name", "type")
  1221  		parent := tx.StartSpan("parent", "internal", nil)
  1222  		for i := 0; i < 3; i++ {
  1223  			child := tx.StartSpanOptions(fmt.Sprint(i), "type", apm.SpanOptions{
  1224  				Parent:   parent.TraceContext(),
  1225  				ExitSpan: true,
  1226  			})
  1227  			child.Duration = time.Microsecond
  1228  			child.End()
  1229  			if i == 1 {
  1230  				parent.End()
  1231  			}
  1232  		}
  1233  		tx.End()
  1234  		tracer.Flush(nil)
  1235  		assertResult(t, tracer.Payloads().Transactions[0], tracer.Payloads().Spans, expect{
  1236  			spanCount:           3,
  1237  			compositeCount:      2,
  1238  			compressionStrategy: "same_kind",
  1239  			compositeSum:        0.002,
  1240  		})
  1241  	})
  1242  }
  1243  
  1244  func TestExitSpanDoesNotOverwriteDestinationServiceResource(t *testing.T) {
  1245  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1246  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{ExitSpan: true})
  1247  		assert.True(t, span.IsExitSpan())
  1248  		span.Context.SetDestinationService(apm.DestinationServiceSpanContext{
  1249  			Resource: "my-custom-resource",
  1250  		})
  1251  		span.Duration = 2 * time.Millisecond
  1252  		span.End()
  1253  	})
  1254  	require.Len(t, spans, 1)
  1255  	assert.Equal(t, spans[0].Context.Destination.Service.Resource, "my-custom-resource")
  1256  }
  1257  
  1258  func TestExitSpanDoesNotOverwriteServiceTarget(t *testing.T) {
  1259  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1260  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{ExitSpan: true})
  1261  		assert.True(t, span.IsExitSpan())
  1262  		span.Context.SetServiceTarget(apm.ServiceTargetSpanContext{
  1263  			Type: "my-custom-resource",
  1264  			Name: "foo",
  1265  		})
  1266  		span.Duration = 2 * time.Millisecond
  1267  		span.End()
  1268  	})
  1269  	require.Len(t, spans, 1)
  1270  	assert.Equal(t, spans[0].Context.Service.Target.Type, "my-custom-resource")
  1271  	assert.Equal(t, spans[0].Context.Service.Target.Name, "foo")
  1272  }
  1273  
  1274  func TestExitSpanDisableInferTarget(t *testing.T) {
  1275  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1276  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{ExitSpan: true})
  1277  		assert.True(t, span.IsExitSpan())
  1278  		span.Context.SetDatabase(apm.DatabaseSpanContext{
  1279  			Type:     "mysql",
  1280  			Instance: "foo",
  1281  		})
  1282  		span.Context.SetServiceTarget(apm.ServiceTargetSpanContext{})
  1283  		span.Duration = 2 * time.Millisecond
  1284  		span.End()
  1285  	})
  1286  	require.Len(t, spans, 1)
  1287  	assert.Empty(t, spans[0].Context.Service.Target.Type)
  1288  	assert.Empty(t, spans[0].Context.Service.Target.Name)
  1289  }
  1290  
  1291  func TestExitSpanInferTarget(t *testing.T) {
  1292  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1293  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{ExitSpan: true})
  1294  		assert.True(t, span.IsExitSpan())
  1295  		span.Context.SetDatabase(apm.DatabaseSpanContext{
  1296  			Type:     "mysql",
  1297  			Instance: "foo",
  1298  		})
  1299  		span.Duration = 2 * time.Millisecond
  1300  		span.End()
  1301  	})
  1302  	require.Len(t, spans, 1)
  1303  	assert.Equal(t, spans[0].Context.Service.Target.Type, "type")
  1304  	assert.Equal(t, spans[0].Context.Service.Target.Name, "foo")
  1305  }
  1306  
  1307  func TestExitSpanInferTargetWithName(t *testing.T) {
  1308  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1309  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{ExitSpan: true})
  1310  		assert.True(t, span.IsExitSpan())
  1311  		span.Context.SetDatabase(apm.DatabaseSpanContext{
  1312  			Type:     "mysql",
  1313  			Instance: "foo",
  1314  		})
  1315  		span.Context.SetServiceTarget(apm.ServiceTargetSpanContext{
  1316  			Name: "bar",
  1317  		})
  1318  		span.Duration = 2 * time.Millisecond
  1319  		span.End()
  1320  	})
  1321  	require.Len(t, spans, 1)
  1322  	assert.Equal(t, spans[0].Context.Service.Target.Type, "type")
  1323  	assert.Equal(t, spans[0].Context.Service.Target.Name, "bar")
  1324  }
  1325  
  1326  func TestTracerStartSpanIDSpecified(t *testing.T) {
  1327  	spanID := apm.SpanID{0, 1, 2, 3, 4, 5, 6, 7}
  1328  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1329  		span, _ := apm.StartSpanOptions(ctx, "name", "type", apm.SpanOptions{SpanID: spanID})
  1330  		span.End()
  1331  	})
  1332  	require.Len(t, spans, 1)
  1333  	assert.Equal(t, model.SpanID(spanID), spans[0].ID)
  1334  }
  1335  
  1336  func TestSpanSampleRate(t *testing.T) {
  1337  	tracer := apmtest.NewRecordingTracer()
  1338  	defer tracer.Close()
  1339  	tracer.SetSampler(apm.NewRatioSampler(0.55555))
  1340  
  1341  	tx := tracer.StartTransactionOptions("name", "type", apm.TransactionOptions{
  1342  		// Use a known transaction ID for deterministic sampling.
  1343  		TransactionID: apm.SpanID{1, 2, 3, 4, 5, 6, 7, 8},
  1344  	})
  1345  	s1 := tx.StartSpan("name", "type", nil)
  1346  	s2 := tx.StartSpan("name", "type", s1)
  1347  	s2.End()
  1348  	s1.End()
  1349  	tx.End()
  1350  	tracer.Flush(nil)
  1351  
  1352  	payloads := tracer.Payloads()
  1353  	assert.Equal(t, 0.5556, *payloads.Transactions[0].SampleRate)
  1354  	assert.Equal(t, 0.5556, *payloads.Spans[0].SampleRate)
  1355  	assert.Equal(t, 0.5556, *payloads.Spans[1].SampleRate)
  1356  }
  1357  
  1358  func TestSpanFastExit(t *testing.T) {
  1359  	type expect struct {
  1360  		spans                  int
  1361  		droppedSpansStatsCount int
  1362  	}
  1363  	tests := []struct {
  1364  		expect expect
  1365  		setup  func() func()
  1366  		name   string
  1367  	}{
  1368  		{
  1369  			name: "DefaultSetting/KeepSpan",
  1370  			expect: expect{
  1371  				spans:                  1,
  1372  				droppedSpansStatsCount: 0,
  1373  			},
  1374  		},
  1375  		{
  1376  			name: "2msSetting/KeepSpan",
  1377  			setup: func() func() {
  1378  				os.Setenv("ELASTIC_APM_EXIT_SPAN_MIN_DURATION", "2ms")
  1379  				return func() { os.Unsetenv("ELASTIC_APM_EXIT_SPAN_MIN_DURATION") }
  1380  			},
  1381  			expect: expect{
  1382  				spans:                  1,
  1383  				droppedSpansStatsCount: 0,
  1384  			},
  1385  		},
  1386  		{
  1387  			name: "3msSetting/DropSpan",
  1388  			setup: func() func() {
  1389  				os.Setenv("ELASTIC_APM_EXIT_SPAN_MIN_DURATION", "3ms")
  1390  				return func() { os.Unsetenv("ELASTIC_APM_EXIT_SPAN_MIN_DURATION") }
  1391  			},
  1392  			expect: expect{
  1393  				spans:                  0,
  1394  				droppedSpansStatsCount: 1,
  1395  			},
  1396  		},
  1397  		{
  1398  			name: "100usSetting/DropSpan",
  1399  			setup: func() func() {
  1400  				os.Setenv("ELASTIC_APM_EXIT_SPAN_MIN_DURATION", "100us")
  1401  				return func() { os.Unsetenv("ELASTIC_APM_EXIT_SPAN_MIN_DURATION") }
  1402  			},
  1403  			expect: expect{
  1404  				spans:                  1,
  1405  				droppedSpansStatsCount: 0,
  1406  			},
  1407  		},
  1408  	}
  1409  	for _, test := range tests {
  1410  		t.Run(test.name, func(t *testing.T) {
  1411  			if test.setup != nil {
  1412  				defer test.setup()()
  1413  			}
  1414  
  1415  			tracer := apmtest.NewRecordingTracer()
  1416  			defer tracer.Close()
  1417  
  1418  			tx := tracer.StartTransaction("name", "type")
  1419  			span := tx.StartSpanOptions("name", "type", apm.SpanOptions{ExitSpan: true})
  1420  			span.Duration = 2 * time.Millisecond
  1421  
  1422  			span.End()
  1423  			tx.End()
  1424  			tracer.Flush(nil)
  1425  			payloads := tracer.Payloads()
  1426  			require.Len(t, payloads.Transactions, 1)
  1427  			assert.Len(t, payloads.Spans, test.expect.spans)
  1428  			assert.Len(t,
  1429  				payloads.Transactions[0].DroppedSpansStats,
  1430  				test.expect.droppedSpansStatsCount,
  1431  			)
  1432  		})
  1433  	}
  1434  }
  1435  
  1436  func TestSpanFastExitWithCompress(t *testing.T) {
  1437  	// This test case asserts compressing spans into a composite:
  1438  	//  * Takes precedence over dropping the spans
  1439  	//  * When spans cannot be compressed but are discardable, they are.
  1440  	//  * The compressed and dropped spans are not counted in tx.started.
  1441  	//  * Dropped spans increment the dropped count.
  1442  	// Since compressed spans rely on the first compressed child's timestamp
  1443  	// to calculate the span duration, we're using a running timestsamp for
  1444  	// the spans.
  1445  
  1446  	tracer := apmtest.NewRecordingTracer()
  1447  	defer tracer.Close()
  1448  	tracer.SetSpanCompressionEnabled(true)
  1449  
  1450  	txts := time.Now()
  1451  	tx := tracer.StartTransactionOptions("name", "type", apm.TransactionOptions{
  1452  		Start: txts,
  1453  	})
  1454  	ctx := apm.ContextWithTransaction(context.Background(), tx)
  1455  	ts := time.Now()
  1456  
  1457  	// Compress 499 spans which are compressable and can be dropped, they will
  1458  	// be compressed since that takes precedence.
  1459  	for i := 0; i < 499; i++ {
  1460  		span, _ := apm.StartSpanOptions(ctx, "compressed", "type", apm.SpanOptions{
  1461  			ExitSpan: true, Start: ts,
  1462  		})
  1463  		span.Duration = time.Millisecond
  1464  		ts = ts.Add(span.Duration)
  1465  		span.End()
  1466  	}
  1467  
  1468  	// This span is compressable and can be dropped too but won't be since its
  1469  	// outcome is "failure".
  1470  	errorSpan, _ := apm.StartSpanOptions(ctx, "compressed", "type", apm.SpanOptions{
  1471  		ExitSpan: true, Start: ts,
  1472  	})
  1473  	errorSpan.Duration = time.Millisecond
  1474  	ts = ts.Add(errorSpan.Duration)
  1475  	errorSpan.Outcome = "failure"
  1476  	errorSpan.End()
  1477  
  1478  	// These spans will be compressed into a composite.
  1479  	for i := 0; i < 100; i++ {
  1480  		span, _ := apm.StartSpanOptions(ctx, "compressed", "anothertype", apm.SpanOptions{
  1481  			ExitSpan: true, Start: ts,
  1482  		})
  1483  		span.Duration = time.Millisecond
  1484  		ts = ts.Add(span.Duration)
  1485  		span.End()
  1486  	}
  1487  
  1488  	// Uncompressable spans are dropped when they are considered fast exit spans
  1489  	// <= 1ms by default. They should not be accounted in the "Started" spans.
  1490  	for i := 0; i < 100; i++ {
  1491  		span, _ := apm.StartSpanOptions(ctx, fmt.Sprint(i), fmt.Sprint(i), apm.SpanOptions{
  1492  			ExitSpan: true, Start: ts,
  1493  		})
  1494  		span.Duration = 500 * time.Microsecond
  1495  		ts = ts.Add(span.Duration)
  1496  		span.End()
  1497  	}
  1498  
  1499  	tx.Duration = ts.Sub(txts)
  1500  	tx.End()
  1501  	tracer.Flush(nil)
  1502  	payloads := tracer.Payloads()
  1503  
  1504  	require.Len(t, payloads.Transactions, 1)
  1505  	defer func() {
  1506  		if t.Failed() {
  1507  			apmtest.WriteTraceTable(os.Stdout, payloads.Transactions[0], payloads.Spans)
  1508  			apmtest.WriteTraceWaterfall(os.Stdout, payloads.Transactions[0], payloads.Spans)
  1509  		}
  1510  	}()
  1511  
  1512  	assert.Len(t, payloads.Spans, 3)
  1513  	transaction := payloads.Transactions[0]
  1514  	assert.Len(t, transaction.DroppedSpansStats, 100)
  1515  	assert.Equal(t, model.SpanCount{
  1516  		Dropped: 100,
  1517  		Started: 3,
  1518  	}, transaction.SpanCount)
  1519  }
  1520  
  1521  func TestSpanFastExitNoTransaction(t *testing.T) {
  1522  	// This test case asserts that a discardable span is not discarded when the
  1523  	// transaction ends before the span, since the stats wouldn't be recorded.
  1524  	tracer := apmtest.NewRecordingTracer()
  1525  	defer tracer.Close()
  1526  
  1527  	tx := tracer.StartTransaction("name", "type")
  1528  	ctx := apm.ContextWithTransaction(context.Background(), tx)
  1529  	span, _ := apm.StartSpanOptions(ctx, "compressed", "type", apm.SpanOptions{ExitSpan: true})
  1530  
  1531  	tx.End()
  1532  	span.Duration = time.Millisecond
  1533  	span.End()
  1534  
  1535  	tracer.Flush(nil)
  1536  	payloads := tracer.Payloads()
  1537  
  1538  	require.Len(t, payloads.Transactions, 1)
  1539  	require.Len(t, payloads.Spans, 1)
  1540  	transaction := payloads.Transactions[0]
  1541  
  1542  	assert.Len(t, transaction.DroppedSpansStats, 0)
  1543  	assert.Equal(t, model.SpanCount{
  1544  		Started: 1,
  1545  		Dropped: 0,
  1546  	}, transaction.SpanCount)
  1547  }
  1548  
  1549  func TestSpanOutcome(t *testing.T) {
  1550  	_, spans, _ := apmtest.WithTransaction(func(ctx context.Context) {
  1551  		span1, _ := apm.StartSpan(ctx, "name", "type")
  1552  		span1.End()
  1553  
  1554  		span2, _ := apm.StartSpan(ctx, "name", "type")
  1555  		span2.Outcome = "unknown"
  1556  		span2.End()
  1557  
  1558  		span3, _ := apm.StartSpan(ctx, "name", "type")
  1559  		span3.Context.SetHTTPStatusCode(200)
  1560  		span3.End()
  1561  
  1562  		span4, _ := apm.StartSpan(ctx, "name", "type")
  1563  		span4.Context.SetHTTPStatusCode(400)
  1564  		span4.End()
  1565  
  1566  		span5, ctx := apm.StartSpan(ctx, "name", "type")
  1567  		apm.CaptureError(ctx, errors.New("an error")).Send()
  1568  		span5.End()
  1569  	})
  1570  
  1571  	require.Len(t, spans, 5)
  1572  	assert.Equal(t, "success", spans[0].Outcome) // default
  1573  	assert.Equal(t, "unknown", spans[1].Outcome) // specified
  1574  	assert.Equal(t, "success", spans[2].Outcome) // HTTP status < 400
  1575  	assert.Equal(t, "failure", spans[3].Outcome) // HTTP status >= 400
  1576  	assert.Equal(t, "failure", spans[4].Outcome)
  1577  }