github.com/newrelic/go-agent@v3.26.0+incompatible/internal/txn_trace.go (about)

     1  // Copyright 2020 New Relic Corporation. All rights reserved.
     2  // SPDX-License-Identifier: Apache-2.0
     3  
     4  package internal
     5  
     6  import (
     7  	"bytes"
     8  	"container/heap"
     9  	"sort"
    10  	"time"
    11  
    12  	"github.com/newrelic/go-agent/internal/jsonx"
    13  )
    14  
    15  // See https://source.datanerd.us/agents/agent-specs/blob/master/Transaction-Trace-LEGACY.md
    16  
    17  type traceNodeHeap []traceNode
    18  
    19  type traceNodeParams struct {
    20  	attributes              map[SpanAttribute]jsonWriter
    21  	StackTrace              StackTrace
    22  	TransactionGUID         string
    23  	exclusiveDurationMillis *float64
    24  }
    25  
    26  type traceNode struct {
    27  	start    segmentTime
    28  	stop     segmentTime
    29  	threadID uint64
    30  	duration time.Duration
    31  	traceNodeParams
    32  	name string
    33  }
    34  
    35  func (h traceNodeHeap) Len() int           { return len(h) }
    36  func (h traceNodeHeap) Less(i, j int) bool { return h[i].duration < h[j].duration }
    37  func (h traceNodeHeap) Swap(i, j int)      { h[i], h[j] = h[j], h[i] }
    38  
    39  // Push and Pop are unused: only heap.Init and heap.Fix are used.
    40  func (h traceNodeHeap) Push(x interface{}) {}
    41  func (h traceNodeHeap) Pop() interface{}   { return nil }
    42  
    43  // TxnTrace contains the work in progress transaction trace.
    44  type TxnTrace struct {
    45  	Enabled             bool
    46  	SegmentThreshold    time.Duration
    47  	StackTraceThreshold time.Duration
    48  	nodes               traceNodeHeap
    49  	maxNodes            int
    50  }
    51  
    52  // getMaxNodes allows the maximum number of nodes to be overwritten for unit
    53  // tests.
    54  func (trace *TxnTrace) getMaxNodes() int {
    55  	if 0 != trace.maxNodes {
    56  		return trace.maxNodes
    57  	}
    58  	return maxTxnTraceNodes
    59  }
    60  
    61  // considerNode exists to prevent unnecessary calls to witnessNode: constructing
    62  // the metric name and params map requires allocations.
    63  func (trace *TxnTrace) considerNode(end segmentEnd) bool {
    64  	return trace.Enabled && (end.duration >= trace.SegmentThreshold)
    65  }
    66  
    67  func (trace *TxnTrace) witnessNode(end segmentEnd, name string, attrs spanAttributeMap, externalGUID string) {
    68  	node := traceNode{
    69  		start:    end.start,
    70  		stop:     end.stop,
    71  		duration: end.duration,
    72  		threadID: end.threadID,
    73  		name:     name,
    74  	}
    75  	node.attributes = attrs
    76  	node.TransactionGUID = externalGUID
    77  	if !trace.considerNode(end) {
    78  		return
    79  	}
    80  	if trace.nodes == nil {
    81  		trace.nodes = make(traceNodeHeap, 0, startingTxnTraceNodes)
    82  	}
    83  	if end.exclusive >= trace.StackTraceThreshold {
    84  		node.StackTrace = GetStackTrace()
    85  	}
    86  	if max := trace.getMaxNodes(); len(trace.nodes) < max {
    87  		trace.nodes = append(trace.nodes, node)
    88  		if len(trace.nodes) == max {
    89  			heap.Init(trace.nodes)
    90  		}
    91  		return
    92  	}
    93  
    94  	if node.duration <= trace.nodes[0].duration {
    95  		return
    96  	}
    97  	trace.nodes[0] = node
    98  	heap.Fix(trace.nodes, 0)
    99  }
   100  
   101  // HarvestTrace contains a finished transaction trace ready for serialization to
   102  // the collector.
   103  type HarvestTrace struct {
   104  	TxnEvent
   105  	Trace TxnTrace
   106  }
   107  
   108  type nodeDetails struct {
   109  	name          string
   110  	relativeStart time.Duration
   111  	relativeStop  time.Duration
   112  	traceNodeParams
   113  }
   114  
   115  func printNodeStart(buf *bytes.Buffer, n nodeDetails) {
   116  	// time.Seconds() is intentionally not used here.  Millisecond
   117  	// precision is enough.
   118  	relativeStartMillis := n.relativeStart.Nanoseconds() / (1000 * 1000)
   119  	relativeStopMillis := n.relativeStop.Nanoseconds() / (1000 * 1000)
   120  
   121  	buf.WriteByte('[')
   122  	jsonx.AppendInt(buf, relativeStartMillis)
   123  	buf.WriteByte(',')
   124  	jsonx.AppendInt(buf, relativeStopMillis)
   125  	buf.WriteByte(',')
   126  	jsonx.AppendString(buf, n.name)
   127  	buf.WriteByte(',')
   128  
   129  	w := jsonFieldsWriter{buf: buf}
   130  	buf.WriteByte('{')
   131  	if nil != n.StackTrace {
   132  		w.writerField("backtrace", n.StackTrace)
   133  	}
   134  	if nil != n.exclusiveDurationMillis {
   135  		w.floatField("exclusive_duration_millis", *n.exclusiveDurationMillis)
   136  	}
   137  	if "" != n.TransactionGUID {
   138  		w.stringField("transaction_guid", n.TransactionGUID)
   139  	}
   140  	for k, v := range n.attributes {
   141  		w.writerField(k.String(), v)
   142  	}
   143  	buf.WriteByte('}')
   144  
   145  	buf.WriteByte(',')
   146  	buf.WriteByte('[')
   147  }
   148  
   149  func printChildren(buf *bytes.Buffer, traceStart time.Time, nodes sortedTraceNodes, next int, stop *segmentStamp, threadID uint64) int {
   150  	firstChild := true
   151  	for {
   152  		if next >= len(nodes) {
   153  			// No more children to print.
   154  			break
   155  		}
   156  		if nodes[next].threadID != threadID {
   157  			// The next node is not of the same thread.  Due to the
   158  			// node sorting, all nodes of the same thread should be
   159  			// together.
   160  			break
   161  		}
   162  		if stop != nil && nodes[next].start.Stamp >= *stop {
   163  			// Make sure this node is a child of the parent that is
   164  			// being printed.
   165  			break
   166  		}
   167  		if firstChild {
   168  			firstChild = false
   169  		} else {
   170  			buf.WriteByte(',')
   171  		}
   172  		printNodeStart(buf, nodeDetails{
   173  			name:            nodes[next].name,
   174  			relativeStart:   nodes[next].start.Time.Sub(traceStart),
   175  			relativeStop:    nodes[next].stop.Time.Sub(traceStart),
   176  			traceNodeParams: nodes[next].traceNodeParams,
   177  		})
   178  		next = printChildren(buf, traceStart, nodes, next+1, &nodes[next].stop.Stamp, threadID)
   179  		buf.WriteString("]]")
   180  
   181  	}
   182  	return next
   183  }
   184  
   185  type sortedTraceNodes []*traceNode
   186  
   187  func (s sortedTraceNodes) Len() int { return len(s) }
   188  func (s sortedTraceNodes) Less(i, j int) bool {
   189  	// threadID is the first sort key and start.Stamp is the second key.
   190  	if s[i].threadID == s[j].threadID {
   191  		return s[i].start.Stamp < s[j].start.Stamp
   192  	}
   193  	return s[i].threadID < s[j].threadID
   194  }
   195  func (s sortedTraceNodes) Swap(i, j int) { s[i], s[j] = s[j], s[i] }
   196  
   197  // MarshalJSON is used for testing.
   198  //
   199  // TODO: Eliminate this entirely by using harvestTraces.Data().
   200  func (trace *HarvestTrace) MarshalJSON() ([]byte, error) {
   201  	buf := bytes.NewBuffer(make([]byte, 0, 100+100*trace.Trace.nodes.Len()))
   202  
   203  	trace.writeJSON(buf)
   204  
   205  	return buf.Bytes(), nil
   206  }
   207  
   208  func (trace *HarvestTrace) writeJSON(buf *bytes.Buffer) {
   209  	nodes := make(sortedTraceNodes, len(trace.Trace.nodes))
   210  	for i := 0; i < len(nodes); i++ {
   211  		nodes[i] = &trace.Trace.nodes[i]
   212  	}
   213  	sort.Sort(nodes)
   214  
   215  	buf.WriteByte('[') // begin trace
   216  
   217  	jsonx.AppendInt(buf, trace.Start.UnixNano()/1000)
   218  	buf.WriteByte(',')
   219  	jsonx.AppendFloat(buf, trace.Duration.Seconds()*1000.0)
   220  	buf.WriteByte(',')
   221  	jsonx.AppendString(buf, trace.FinalName)
   222  	buf.WriteByte(',')
   223  	if uri, _ := trace.Attrs.GetAgentValue(attributeRequestURI, destTxnTrace); "" != uri {
   224  		jsonx.AppendString(buf, uri)
   225  	} else {
   226  		buf.WriteString("null")
   227  	}
   228  	buf.WriteByte(',')
   229  
   230  	buf.WriteByte('[') // begin trace data
   231  
   232  	// If the trace string pool is used, insert another array here.
   233  
   234  	jsonx.AppendFloat(buf, 0.0) // unused timestamp
   235  	buf.WriteByte(',')          //
   236  	buf.WriteString("{}")       // unused: formerly request parameters
   237  	buf.WriteByte(',')          //
   238  	buf.WriteString("{}")       // unused: formerly custom parameters
   239  	buf.WriteByte(',')          //
   240  
   241  	printNodeStart(buf, nodeDetails{ // begin outer root
   242  		name:          "ROOT",
   243  		relativeStart: 0,
   244  		relativeStop:  trace.Duration,
   245  	})
   246  
   247  	// exclusive_duration_millis field is added to fix the transaction trace
   248  	// summary tab.  If exclusive_duration_millis is not provided, the UIs
   249  	// will calculate exclusive time, which doesn't work for this root node
   250  	// since all async goroutines are children of this root.
   251  	exclusiveDurationMillis := trace.Duration.Seconds() * 1000.0
   252  	details := nodeDetails{ // begin inner root
   253  		name:          trace.FinalName,
   254  		relativeStart: 0,
   255  		relativeStop:  trace.Duration,
   256  	}
   257  	details.exclusiveDurationMillis = &exclusiveDurationMillis
   258  	printNodeStart(buf, details)
   259  
   260  	for next := 0; next < len(nodes); {
   261  		if next > 0 {
   262  			buf.WriteByte(',')
   263  		}
   264  		// We put each thread's nodes into the root node instead of the
   265  		// node that spawned the thread. This approach is simple and
   266  		// works when the segment which spawned a thread has been pruned
   267  		// from the trace.  Each call to printChildren prints one
   268  		// thread.
   269  		next = printChildren(buf, trace.Start, nodes, next, nil, nodes[next].threadID)
   270  	}
   271  
   272  	buf.WriteString("]]") // end outer root
   273  	buf.WriteString("]]") // end inner root
   274  
   275  	buf.WriteByte(',')
   276  	buf.WriteByte('{')
   277  	buf.WriteString(`"agentAttributes":`)
   278  	agentAttributesJSON(trace.Attrs, buf, destTxnTrace)
   279  	buf.WriteByte(',')
   280  	buf.WriteString(`"userAttributes":`)
   281  	userAttributesJSON(trace.Attrs, buf, destTxnTrace, nil)
   282  	buf.WriteByte(',')
   283  	buf.WriteString(`"intrinsics":`)
   284  	intrinsicsJSON(&trace.TxnEvent, buf)
   285  	buf.WriteByte('}')
   286  
   287  	// If the trace string pool is used, end another array here.
   288  
   289  	buf.WriteByte(']') // end trace data
   290  
   291  	// catGUID
   292  	buf.WriteByte(',')
   293  	if trace.CrossProcess.Used() && trace.CrossProcess.GUID != "" {
   294  		jsonx.AppendString(buf, trace.CrossProcess.GUID)
   295  	} else if trace.BetterCAT.Enabled {
   296  		jsonx.AppendString(buf, trace.BetterCAT.TraceID())
   297  	} else {
   298  		buf.WriteString(`""`)
   299  	}
   300  	buf.WriteByte(',')       //
   301  	buf.WriteString(`null`)  // reserved for future use
   302  	buf.WriteByte(',')       //
   303  	buf.WriteString(`false`) // ForcePersist is not yet supported
   304  	buf.WriteByte(',')       //
   305  	buf.WriteString(`null`)  // X-Ray sessions not supported
   306  	buf.WriteByte(',')       //
   307  
   308  	// Synthetics are supported:
   309  	if trace.CrossProcess.IsSynthetics() {
   310  		jsonx.AppendString(buf, trace.CrossProcess.Synthetics.ResourceID)
   311  	} else {
   312  		buf.WriteString(`""`)
   313  	}
   314  
   315  	buf.WriteByte(']') // end trace
   316  }
   317  
   318  type txnTraceHeap []*HarvestTrace
   319  
   320  func (h *txnTraceHeap) isEmpty() bool {
   321  	return 0 == len(*h)
   322  }
   323  
   324  func newTxnTraceHeap(max int) *txnTraceHeap {
   325  	h := make(txnTraceHeap, 0, max)
   326  	heap.Init(&h)
   327  	return &h
   328  }
   329  
   330  // Implement sort.Interface.
   331  func (h txnTraceHeap) Len() int           { return len(h) }
   332  func (h txnTraceHeap) Less(i, j int) bool { return h[i].Duration < h[j].Duration }
   333  func (h txnTraceHeap) Swap(i, j int)      { h[i], h[j] = h[j], h[i] }
   334  
   335  // Implement heap.Interface.
   336  func (h *txnTraceHeap) Push(x interface{}) { *h = append(*h, x.(*HarvestTrace)) }
   337  
   338  func (h *txnTraceHeap) Pop() interface{} {
   339  	old := *h
   340  	n := len(old)
   341  	x := old[n-1]
   342  	*h = old[0 : n-1]
   343  	return x
   344  }
   345  
   346  func (h *txnTraceHeap) isKeeper(t *HarvestTrace) bool {
   347  	if len(*h) < cap(*h) {
   348  		return true
   349  	}
   350  	return t.Duration >= (*h)[0].Duration
   351  }
   352  
   353  func (h *txnTraceHeap) addTxnTrace(t *HarvestTrace) {
   354  	if len(*h) < cap(*h) {
   355  		heap.Push(h, t)
   356  		return
   357  	}
   358  
   359  	if t.Duration <= (*h)[0].Duration {
   360  		return
   361  	}
   362  	heap.Pop(h)
   363  	heap.Push(h, t)
   364  }
   365  
   366  type harvestTraces struct {
   367  	regular    *txnTraceHeap
   368  	synthetics *txnTraceHeap
   369  }
   370  
   371  func newHarvestTraces() *harvestTraces {
   372  	return &harvestTraces{
   373  		regular:    newTxnTraceHeap(maxRegularTraces),
   374  		synthetics: newTxnTraceHeap(maxSyntheticsTraces),
   375  	}
   376  }
   377  
   378  func (traces *harvestTraces) Len() int {
   379  	return traces.regular.Len() + traces.synthetics.Len()
   380  }
   381  
   382  func (traces *harvestTraces) Witness(trace HarvestTrace) {
   383  	traceHeap := traces.regular
   384  	if trace.CrossProcess.IsSynthetics() {
   385  		traceHeap = traces.synthetics
   386  	}
   387  
   388  	if traceHeap.isKeeper(&trace) {
   389  		cpy := new(HarvestTrace)
   390  		*cpy = trace
   391  		traceHeap.addTxnTrace(cpy)
   392  	}
   393  }
   394  
   395  func (traces *harvestTraces) Data(agentRunID string, harvestStart time.Time) ([]byte, error) {
   396  	if traces.Len() == 0 {
   397  		return nil, nil
   398  	}
   399  
   400  	// This estimate is used to guess the size of the buffer.  No worries if
   401  	// the estimate is small since the buffer will be lengthened as
   402  	// necessary.  This is just about minimizing reallocations.
   403  	estimate := 512
   404  	for _, t := range *traces.regular {
   405  		estimate += 100 * t.Trace.nodes.Len()
   406  	}
   407  	for _, t := range *traces.synthetics {
   408  		estimate += 100 * t.Trace.nodes.Len()
   409  	}
   410  
   411  	buf := bytes.NewBuffer(make([]byte, 0, estimate))
   412  	buf.WriteByte('[')
   413  	jsonx.AppendString(buf, agentRunID)
   414  	buf.WriteByte(',')
   415  	buf.WriteByte('[')
   416  
   417  	// use a function to add traces to the buffer to avoid duplicating comma
   418  	// logic in both loops
   419  	firstTrace := true
   420  	addTrace := func(trace *HarvestTrace) {
   421  		if firstTrace {
   422  			firstTrace = false
   423  		} else {
   424  			buf.WriteByte(',')
   425  		}
   426  		trace.writeJSON(buf)
   427  	}
   428  
   429  	for _, trace := range *traces.regular {
   430  		addTrace(trace)
   431  	}
   432  	for _, trace := range *traces.synthetics {
   433  		addTrace(trace)
   434  	}
   435  	buf.WriteByte(']')
   436  	buf.WriteByte(']')
   437  
   438  	return buf.Bytes(), nil
   439  }
   440  
   441  func (traces *harvestTraces) slice() []*HarvestTrace {
   442  	out := make([]*HarvestTrace, 0, traces.Len())
   443  	out = append(out, (*traces.regular)...)
   444  	out = append(out, (*traces.synthetics)...)
   445  
   446  	return out
   447  }
   448  
   449  func (traces *harvestTraces) MergeIntoHarvest(h *Harvest) {}
   450  
   451  func (traces *harvestTraces) EndpointMethod() string {
   452  	return cmdTxnTraces
   453  }