improve logging of spans in trace log level

packages/datadog-core/src/storage.js

@@ -21,8 +21,16 @@ class DatadogStorage {
     this._storage.exit(callback, ...args)
   }
 
-  getStore () {
-    const handle = this._storage.getStore()
+  // TODO: Refactor the Scope class to use a span-only store and remove this.
+  getHandle () {
+    return this._storage.getStore()
+  }
+
+  getStore (handle) {
+    if (!handle) {
+      handle = this._storage.getStore()
+    }
+
     return stores.get(handle)
   }
 
@@ -50,6 +58,7 @@ const storage = function (namespace) {
 storage.disable = legacyStorage.disable.bind(legacyStorage)
 storage.enterWith = legacyStorage.enterWith.bind(legacyStorage)
 storage.exit = legacyStorage.exit.bind(legacyStorage)
+storage.getHandle = legacyStorage.getHandle.bind(legacyStorage)
 storage.getStore = legacyStorage.getStore.bind(legacyStorage)
 storage.run = legacyStorage.run.bind(legacyStorage)
 

packages/dd-trace/src/log/index.js

@@ -65,11 +65,8 @@ const log = {
 
       const stack = logRecord.stack.split('\n')
       const fn = stack[1].replace(/^\s+at ([^\s]+) .+/, '$1')
-      const params = args.map(a => {
-        return a && a.hasOwnProperty('toString') && typeof a.toString === 'function'
-          ? a.toString()
-          : inspect(a, { depth: 3, breakLength: Infinity, compact: true })
-      }).join(', ')
+      const options = { depth: 2, breakLength: Infinity, compact: true, maxArrayLength: Infinity }
+      const params = args.map(a => inspect(a, options)).join(', ')
 
       stack[0] = `Trace: ${fn}(${params})`
 

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

@@ -6,7 +6,7 @@ const { storage } = require('../../../datadog-core') // TODO: noop storage?
 
 class NoopSpan {
   constructor (tracer, parent) {
-    this._store = storage.getStore()
+    this._store = storage.getHandle()
     this._noopTracer = tracer
     this._noopContext = this._createContext(parent)
   }

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

@@ -14,6 +14,7 @@ const { storage } = require('../../../datadog-core')
 const telemetryMetrics = require('../telemetry/metrics')
 const { channel } = require('dc-polyfill')
 const spanleak = require('../spanleak')
+const util = require('util')
 
 const tracerMetrics = telemetryMetrics.manager.namespace('tracers')
 
@@ -64,7 +65,7 @@ class DatadogSpan {
     this._debug = debug
     this._processor = processor
     this._prioritySampler = prioritySampler
-    this._store = storage.getStore()
+    this._store = storage.getHandle()
     this._duration = undefined
 
     this._events = []
@@ -105,6 +106,15 @@ class DatadogSpan {
     }
   }
 
+  [util.inspect.custom] () {
+    return {
+      ...this,
+      _parentTracer: `[${this._parentTracer.constructor.name}]`,
+      _prioritySampler: `[${this._prioritySampler.constructor.name}]`,
+      _processor: `[${this._processor.constructor.name}]`
+    }
+  }
+
   toString () {
     const spanContext = this.context()
     const resourceName = spanContext._tags['resource.name'] || ''

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

@@ -1,5 +1,6 @@
 'use strict'
 
+const util = require('util')
 const { AUTO_KEEP } = require('../../../../ext/priority')
 
 // the lowercase, hex encoded upper 64 bits of a 128-bit trace id, if present
@@ -31,6 +32,17 @@ class DatadogSpanContext {
     this._otelSpanContext = undefined
   }
 
+  [util.inspect.custom] () {
+    return {
+      ...this,
+      _trace: {
+        ...this._trace,
+        started: '[Array]',
+        finished: '[Array]'
+      }
+    }
+  }
+
   toTraceId (get128bitId = false) {
     if (get128bitId) {
       return this._traceId.toBuffer().length <= 8 && this._trace.tags[TRACE_ID_128]

packages/dd-trace/src/scope.js

@@ -17,7 +17,7 @@ class Scope {
     if (typeof callback !== 'function') return callback
 
     const oldStore = storage.getStore()
-    const newStore = span ? span._store : oldStore
+    const newStore = span ? storage.getStore(span._store) : oldStore
 
     storage.enterWith({ ...newStore, span })
 

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

@@ -147,14 +147,18 @@ describe('log', () => {
       })
 
       it('should log to console after setting log level to trace', function foo () {
+        class Foo {
+          constructor () {
+            this.bar = 'baz'
+          }
+        }
+
         log.toggle(true, 'trace')
-        log.trace('argument', { hello: 'world' }, {
-          toString: () => 'string'
-        }, { foo: 'bar' })
+        log.trace('argument', { hello: 'world' }, new Foo())
 
         expect(console.debug).to.have.been.calledOnce
         expect(console.debug.firstCall.args[0]).to.match(
-          /^Trace: Test.foo\('argument', { hello: 'world' }, string, { foo: 'bar' }\)/
+          /^Trace: Test.foo\('argument', { hello: 'world' }, Foo { bar: 'baz' }\)/
         )
         expect(console.debug.firstCall.args[0].split('\n').length).to.be.gte(3)
       })