Khanayan123/implement span events (#4386)

* implement span events and record exception api

packages/dd-trace/src/format.js

@@ -34,6 +34,7 @@ function format (span) {
   const formatted = formatSpan(span)
 
   extractSpanLinks(formatted, span)
+  extractSpanEvents(formatted, span)
   extractRootTags(formatted, span)
   extractChunkTags(formatted, span)
   extractTags(formatted, span)
@@ -88,6 +89,22 @@ function extractSpanLinks (trace, span) {
   if (links.length > 0) { trace.meta['_dd.span_links'] = JSON.stringify(links) }
 }
 
+function extractSpanEvents (trace, span) {
+  const events = []
+  if (span._events) {
+    for (const event of span._events) {
+      const formattedEvent = {
+        name: event.name,
+        time_unix_nano: Math.round(event.startTime * 1e6),
+        attributes: event.attributes && Object.keys(event.attributes).length > 0 ? event.attributes : undefined
+      }
+
+      events.push(formattedEvent)
+    }
+  }
+  if (events.length > 0) { trace.meta.events = JSON.stringify(events) }
+}
+
 function extractTags (trace, span) {
   const context = span.context()
   const origin = context._trace.origin
@@ -134,15 +151,17 @@ function extractTags (trace, span) {
       case ERROR_STACK:
         // HACK: remove when implemented in the backend
         if (context._name !== 'fs.operation') {
-          trace.error = 1
+          // HACK: to ensure otel.recordException does not influence trace.error
+          if (tags.setTraceError) {
+            trace.error = 1
+          }
         } else {
           break
         }
       default: // eslint-disable-line no-fallthrough
         addTag(trace.meta, trace.metrics, tag, tags[tag])
     }
   }
-
   setSingleSpanIngestionTags(trace, context._spanSampling)
 
   addTag(trace.meta, trace.metrics, 'language', 'javascript')

packages/dd-trace/src/opentelemetry/span.js

@@ -20,6 +20,20 @@ function hrTimeToMilliseconds (time) {
   return time[0] * 1e3 + time[1] / 1e6
 }
 
+function isTimeInput (startTime) {
+  if (typeof startTime === 'number') {
+    return true
+  }
+  if (startTime instanceof Date) {
+    return true
+  }
+  if (Array.isArray(startTime) && startTime.length === 2 &&
+      typeof startTime[0] === 'number' && typeof startTime[1] === 'number') {
+    return true
+  }
+  return false
+}
+
 const spanKindNames = {
   [api.SpanKind.INTERNAL]: kinds.INTERNAL,
   [api.SpanKind.SERVER]: kinds.SERVER,
@@ -196,11 +210,6 @@ class Span {
     return this
   }
 
-  addEvent (name, attributesOrStartTime, startTime) {
-    api.diag.warn('Events not supported')
-    return this
-  }
-
   addLink (context, attributes) {
     // extract dd context
     const ddSpanContext = context._ddContext
@@ -244,12 +253,29 @@ class Span {
     return this.ended === false
   }
 
-  recordException (exception) {
+  addEvent (name, attributesOrStartTime, startTime) {
+    startTime = attributesOrStartTime && isTimeInput(attributesOrStartTime) ? attributesOrStartTime : startTime
+    const hrStartTime = timeInputToHrTime(startTime || (performance.now() + timeOrigin))
+    startTime = hrTimeToMilliseconds(hrStartTime)
+
+    this._ddSpan.addEvent(name, attributesOrStartTime, startTime)
+    return this
+  }
+
+  recordException (exception, timeInput) {
+    // HACK: identifier is added so that trace.error remains unchanged after a call to otel.recordException
     this._ddSpan.addTags({
       [ERROR_TYPE]: exception.name,
       [ERROR_MESSAGE]: exception.message,
-      [ERROR_STACK]: exception.stack
+      [ERROR_STACK]: exception.stack,
+      doNotSetTraceError: true
     })
+    const attributes = {}
+    if (exception.message) attributes['exception.message'] = exception.message
+    if (exception.type) attributes['exception.type'] = exception.type
+    if (exception.escaped) attributes['exception.escaped'] = exception.escaped
+    if (exception.stack) attributes['exception.stacktrace'] = exception.stack
+    this.addEvent(exception.name, attributes, timeInput)
   }
 
   get duration () {

packages/dd-trace/src/opentracing/span.js

@@ -67,6 +67,8 @@ class DatadogSpan {
     this._store = storage.getStore()
     this._duration = undefined
 
+    this._events = []
+
     // For internal use only. You probably want `context()._name`.
     // This name property is not updated when the span name changes.
     // This is necessary for span count metrics.
@@ -163,6 +165,19 @@ class DatadogSpan {
     })
   }
 
+  addEvent (name, attributesOrStartTime, startTime) {
+    const event = { name }
+    if (attributesOrStartTime) {
+      if (typeof attributesOrStartTime === 'object') {
+        event.attributes = this._sanitizeEventAttributes(attributesOrStartTime)
+      } else {
+        startTime = attributesOrStartTime
+      }
+    }
+    event.startTime = startTime || this._getTime()
+    this._events.push(event)
+  }
+
   finish (finishTime) {
     if (this._duration !== undefined) {
       return
@@ -221,7 +236,30 @@ class DatadogSpan {
       const [key, value] = entry
       addArrayOrScalarAttributes(key, value)
     })
+    return sanitizedAttributes
+  }
+
+  _sanitizeEventAttributes (attributes = {}) {
+    const sanitizedAttributes = {}
 
+    for (const key in attributes) {
+      const value = attributes[key]
+      if (Array.isArray(value)) {
+        const newArray = []
+        for (const subkey in value) {
+          if (ALLOWED.includes(typeof value[subkey])) {
+            newArray.push(value[subkey])
+          } else {
+            log.warn('Dropping span event attribute. It is not of an allowed type')
+          }
+        }
+        sanitizedAttributes[key] = newArray
+      } else if (ALLOWED.includes(typeof value)) {
+        sanitizedAttributes[key] = value
+      } else {
+        log.warn('Dropping span event attribute. It is not of an allowed type')
+      }
+    }
     return sanitizedAttributes
   }
 

packages/dd-trace/src/tagger.js

@@ -1,6 +1,10 @@
 'use strict'
 
+const constants = require('./constants')
 const log = require('./log')
+const ERROR_MESSAGE = constants.ERROR_MESSAGE
+const ERROR_STACK = constants.ERROR_STACK
+const ERROR_TYPE = constants.ERROR_TYPE
 
 const otelTagMap = {
   'deployment.environment': 'env',
@@ -14,7 +18,6 @@ function add (carrier, keyValuePairs, parseOtelTags = false) {
   if (Array.isArray(keyValuePairs)) {
     return keyValuePairs.forEach(tags => add(carrier, tags))
   }
-
   try {
     if (typeof keyValuePairs === 'string') {
       const segments = keyValuePairs.split(',')
@@ -32,6 +35,12 @@ function add (carrier, keyValuePairs, parseOtelTags = false) {
         carrier[key.trim()] = value.trim()
       }
     } else {
+      // HACK: to ensure otel.recordException does not influence trace.error
+      if (ERROR_MESSAGE in keyValuePairs || ERROR_STACK in keyValuePairs || ERROR_TYPE in keyValuePairs) {
+        if (!('doNotSetTraceError' in keyValuePairs)) {
+          carrier.setTraceError = true
+        }
+      }
       Object.assign(carrier, keyValuePairs)
     }
   } catch (e) {

packages/dd-trace/test/encode/0.4.spec.js

@@ -185,6 +185,21 @@ describe('encode', () => {
     })
   })
 
+  it('should encode span events', () => {
+    const encodedLink = '[{"name":"Something went so wrong","time_unix_nano":1000000},' +
+    '{"name":"I can sing!!! acbdefggnmdfsdv k 2e2ev;!|=xxx","time_unix_nano":1633023102000000,' +
+    '"attributes":{"emotion":"happy","rating":9.8,"other":[1,9.5,1],"idol":false}}]'
+
+    data[0].meta.events = encodedLink
+
+    encoder.encode(data)
+
+    const buffer = encoder.makePayload()
+    const decoded = msgpack.decode(buffer, { codec })
+    const trace = decoded[0]
+    expect(trace[0].meta.events).to.deep.equal(encodedLink)
+  })
+
   it('should encode spanLinks', () => {
     const traceIdHigh = id('10')
     const traceId = id('1234abcd1234abcd')

packages/dd-trace/test/encode/0.5.spec.js

@@ -65,6 +65,27 @@ describe('encode 0.5', () => {
     expect(stringMap[trace[0][11]]).to.equal('') // unset
   })
 
+  it('should encode span events', () => {
+    const encodedLink = '[{"name":"Something went so wrong","time_unix_nano":1000000},' +
+    '{"name":"I can sing!!! acbdefggnmdfsdv k 2e2ev;!|=xxx","time_unix_nano":1633023102000000,' +
+    '"attributes":{"emotion":"happy","rating":9.8,"other":[1,9.5,1],"idol":false}}]'
+
+    data[0].meta.events = encodedLink
+
+    encoder.encode(data)
+
+    const buffer = encoder.makePayload()
+    const decoded = msgpack.decode(buffer, { codec })
+    const stringMap = decoded[0]
+    const trace = decoded[1][0]
+    expect(stringMap).to.include('events')
+    expect(stringMap).to.include(encodedLink)
+    expect(trace[0][9]).to.include({
+      [stringMap.indexOf('bar')]: stringMap.indexOf('baz'),
+      [stringMap.indexOf('events')]: stringMap.indexOf(encodedLink)
+    })
+  })
+
   it('should encode span links', () => {
     const traceIdHigh = id('10')
     const traceId = id('1234abcd1234abcd')

packages/dd-trace/test/format.spec.js

@@ -87,6 +87,27 @@ describe('format', () => {
   })
 
   describe('format', () => {
+    it('should format span events', () => {
+      span._events = [
+        { name: 'Something went so wrong', startTime: 1 },
+        {
+          name: 'I can sing!!! acbdefggnmdfsdv k 2e2ev;!|=xxx',
+          attributes: { emotion: 'happy', rating: 9.8, other: [1, 9.5, 1], idol: false },
+          startTime: 1633023102
+        }
+      ]
+
+      trace = format(span)
+      const spanEvents = JSON.parse(trace.meta.events)
+      expect(spanEvents).to.deep.equal([{
+        name: 'Something went so wrong',
+        time_unix_nano: 1000000
+      }, {
+        name: 'I can sing!!! acbdefggnmdfsdv k 2e2ev;!|=xxx',
+        time_unix_nano: 1633023102000000,
+        attributes: { emotion: 'happy', rating: 9.8, other: [1, 9.5, 1], idol: false }
+      }])
+    })
     it('should convert a span to the correct trace format', () => {
       trace = format(span)
 
@@ -403,14 +424,31 @@ describe('format', () => {
       })
     })
 
-    it('should set the error flag when there is an error-related tag', () => {
+    it('should not set the error flag when there is an error-related tag without a set trace tag', () => {
+      spanContext._tags[ERROR_TYPE] = 'Error'
+      spanContext._tags[ERROR_MESSAGE] = 'boom'
+      spanContext._tags[ERROR_STACK] = ''
+
+      trace = format(span)
+
+      expect(trace.error).to.equal(0)
+    })
+
+    it('should set the error flag when there is an error-related tag with should setTrace', () => {
       spanContext._tags[ERROR_TYPE] = 'Error'
       spanContext._tags[ERROR_MESSAGE] = 'boom'
       spanContext._tags[ERROR_STACK] = ''
+      spanContext._tags.setTraceError = 1
 
       trace = format(span)
 
       expect(trace.error).to.equal(1)
+
+      spanContext._tags[ERROR_TYPE] = 'foo'
+      spanContext._tags[ERROR_MESSAGE] = 'foo'
+      spanContext._tags[ERROR_STACK] = 'foo'
+
+      expect(trace.error).to.equal(1)
     })
 
     it('should not set the error flag for internal spans with error tags', () => {