fix log publish format (#7293)

Author: rochdev

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

@@ -31,31 +31,31 @@ const log = {
   use (logger) {
     config.logger = logger
     logWriter.use(logger)
-    return this
+    return log
   },
 
   toggle (enabled, logLevel) {
     config.enabled = enabled
     config.logLevel = logLevel
     logWriter.toggle(enabled, logLevel)
-    return this
+    return log
   },
 
   reset () {
     logWriter.reset()
-    this._deprecate = memoize((code, message) => {
-      errorChannel.publish(Log.parse(message))
+    log._deprecate = memoize((code, message) => {
+      publishFormatted(errorChannel, null, message)
       return true
     })
 
-    return this
+    return log
   },
 
   trace (...args) {
     if (traceChannel.hasSubscribers) {
       const logRecord = {}
 
-      Error.captureStackTrace(logRecord, this.trace)
+      Error.captureStackTrace(logRecord, log.trace)
 
       const stack = logRecord.stack.split('\n')
       const fn = stack[1].replace(/^\s+at ([^\s]+) .+/, '$1')
@@ -64,49 +64,46 @@ const log = {
 
       stack[0] = `Trace: ${fn}(${params})`
 
-      traceChannel.publish(Log.parse(stack.join('\n')))
+      publishFormatted(traceChannel, null, stack.join('\n'))
     }
-    return this
+    return log
   },
 
   debug (...args) {
-    if (debugChannel.hasSubscribers) {
-      debugChannel.publish(Log.parse(...args))
-    }
-    return this
+    publishFormatted(debugChannel, null, ...args)
+    return log
   },
 
   info (...args) {
-    if (infoChannel.hasSubscribers) {
-      infoChannel.publish(Log.parse(...args))
-    }
-    return this
+    publishFormatted(infoChannel, null, ...args)
+    return log
   },
 
   warn (...args) {
-    if (warnChannel.hasSubscribers) {
-      warnChannel.publish(Log.parse(...args))
-    }
-    return this
+    publishFormatted(warnChannel, null, ...args)
+    return log
   },
 
   error (...args) {
-    if (errorChannel.hasSubscribers) {
-      errorChannel.publish(Log.parse(...args))
-    }
-    return this
+    publishFormatted(errorChannel, formatted => {
+      const stackTraceLimitBackup = Error.stackTraceLimit
+      Error.stackTraceLimit = 0
+      const newError = new Error(formatted)
+      Error.stackTraceLimit = stackTraceLimitBackup
+      Error.captureStackTrace(newError, log.error)
+      return newError
+    }, ...args)
+    return log
   },
 
   errorWithoutTelemetry (...args) {
     args.push(NO_TRANSMIT)
-    if (errorChannel.hasSubscribers) {
-      errorChannel.publish(Log.parse(...args))
-    }
-    return this
+    publishFormatted(errorChannel, null, ...args)
+    return log
   },
 
   deprecate (code, message) {
-    return this._deprecate(code, message)
+    return log._deprecate(code, message)
   },
 
   isEnabled (fleetStableConfigValue, localStableConfigValue) {
@@ -133,7 +130,25 @@ const log = {
   }
 }
 
-logWriter.setStackTraceLimitFunction(log.error)
+function publishFormatted (ch, formatter, ...args) {
+  if (ch.hasSubscribers) {
+    const log = Log.parse(...args)
+    const { formatted, cause } = getErrorLog(log)
+
+    // calling twice ch.publish() because Error cause is only available in Node.js v16.9.0
+    // TODO: replace it with Error(message, { cause }) when cause has broad support
+    if (formatted) ch.publish(formatter?.(formatted) || formatted)
+    if (cause) ch.publish(cause)
+  }
+}
+
+function getErrorLog (err) {
+  if (typeof err?.delegate === 'function') {
+    const result = err.delegate()
+    return Array.isArray(result) ? Log.parse(...result) : Log.parse(result)
+  }
+  return err
+}
 
 log.reset()
 

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

@@ -2,7 +2,6 @@
 
 const { storage } = require('../../../datadog-core')
 const { LogChannel } = require('./channels')
-const { Log } = require('./log')
 const defaultLogger = {
   debug: msg => console.debug(msg), /* eslint-disable-line no-console */
   info: msg => console.info(msg), /* eslint-disable-line no-console */
@@ -13,7 +12,6 @@ const defaultLogger = {
 let enabled = false
 let logger = defaultLogger
 let logChannel = new LogChannel()
-let stackTraceLimitFunction = onError
 
 function withNoop (fn) {
   const store = storage('legacy').getStore()
@@ -24,15 +22,15 @@ function withNoop (fn) {
 }
 
 function unsubscribeAll () {
-  logChannel.unsubscribe({ trace: onTrace, debug: onDebug, info: onInfo, warn: onWarn, error: onError })
+  logChannel.unsubscribe({ trace, debug, info, warn, error })
 }
 
 function toggleSubscription (enable, level) {
   unsubscribeAll()
 
   if (enable) {
     logChannel = new LogChannel(level)
-    logChannel.subscribe({ trace: onTrace, debug: onDebug, info: onInfo, warn: onWarn, error: onError })
+    logChannel.subscribe({ trace, debug, info, warn, error })
   }
 }
 
@@ -53,89 +51,26 @@ function reset () {
   toggleSubscription(false)
 }
 
-function getErrorLog (err) {
-  if (typeof err?.delegate === 'function') {
-    const result = err.delegate()
-    return Array.isArray(result) ? Log.parse(...result) : Log.parse(result)
-  }
-  return err
-}
-
-function setStackTraceLimitFunction (fn) {
-  if (typeof fn !== 'function') {
-    throw new TypeError('stackTraceLimitFunction must be a function')
-  }
-  stackTraceLimitFunction = fn
-}
-
-function onError (err) {
-  const { formatted, cause } = getErrorLog(err)
-
-  // calling twice logger.error() because Error cause is only available in Node.js v16.9.0
-  // TODO: replace it with Error(message, { cause }) when cause has broad support
-  if (formatted) {
-    withNoop(() => {
-      const stackTraceLimitBackup = Error.stackTraceLimit
-      Error.stackTraceLimit = 0
-      const newError = new Error(formatted)
-      Error.stackTraceLimit = stackTraceLimitBackup
-      Error.captureStackTrace(newError, stackTraceLimitFunction)
-      logger.error(newError)
-    })
-  }
-  if (cause) withNoop(() => logger.error(cause))
+function error (err) {
+  withNoop(() => logger.error(err))
 }
 
-function onWarn (log) {
-  const { formatted, cause } = getErrorLog(log)
-  if (formatted) withNoop(() => logger.warn(formatted))
-  if (cause) withNoop(() => logger.warn(cause))
+function warn (log) {
+  withNoop(() => logger.warn ? logger.warn(log) : logger.debug(log))
 }
 
-function onInfo (log) {
-  const { formatted, cause } = getErrorLog(log)
-  if (formatted) withNoop(() => logger.info(formatted))
-  if (cause) withNoop(() => logger.info(cause))
+function info (log) {
+  withNoop(() => logger.info ? logger.info(log) : logger.debug(log))
 }
 
-function onDebug (log) {
-  const { formatted, cause } = getErrorLog(log)
-  if (formatted) withNoop(() => logger.debug(formatted))
-  if (cause) withNoop(() => logger.debug(cause))
+function debug (log) {
+  withNoop(() => logger.debug(log))
 }
 
-function onTrace (log) {
-  const { formatted, cause } = getErrorLog(log)
+function trace (log) {
   // Using logger.debug() because not all loggers have trace level,
   // and console.trace() has a completely different meaning.
-  if (formatted) withNoop(() => logger.debug(formatted))
-  if (cause) withNoop(() => logger.debug(cause))
-}
-
-function error (...args) {
-  onError(Log.parse(...args))
-}
-
-function warn (...args) {
-  const log = Log.parse(...args)
-  if (!logger.warn) return onDebug(log)
-
-  onWarn(log)
-}
-
-function info (...args) {
-  const log = Log.parse(...args)
-  if (!logger.info) return onDebug(log)
-
-  onInfo(log)
-}
-
-function debug (...args) {
-  onDebug(Log.parse(...args))
-}
-
-function trace (...args) {
-  onTrace(Log.parse(...args))
+  withNoop(() => logger.debug(log))
 }
 
-module.exports = { use, toggle, reset, error, warn, info, debug, trace, setStackTraceLimitFunction }
+module.exports = { use, toggle, reset, error, warn, info, debug, trace }

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

@@ -3,18 +3,16 @@
 const assert = require('node:assert/strict')
 const http = require('node:http')
 
-const { channel } = require('dc-polyfill')
 const express = require('express')
 const upload = require('multer')()
 const proxyquire = require('proxyquire').noCallThru()
 const { describe, it, beforeEach, afterEach } = require('mocha')
 
 const { assertObjectContains } = require('../../../integration-tests/helpers')
 require('./setup/core')
+const log = require('../src/log')
 const { getConfigFresh } = require('./helpers/config')
 
-const debugChannel = channel('datadog:log:debug')
-
 describe('Flare', () => {
   let flare
   let startupLog
@@ -155,9 +153,9 @@ describe('Flare', () => {
     flare.enable(tracerConfig)
     flare.prepare('debug')
 
-    debugChannel.publish('foo')
-    debugChannel.publish('bar')
-    debugChannel.publish({ foo: 'bar' })
+    log.debug('foo')
+    log.debug('bar')
+    log.debug(JSON.stringify({ foo: 'bar' }))
 
     flare.send(task)
   })

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

@@ -457,8 +457,8 @@ describe('log', () => {
 
         sinon.assert.calledOnce(console.error)
         const consoleErrorArg = console.error.getCall(0).args[0]
-        assert.strictEqual(typeof consoleErrorArg, 'object')
-        assert.strictEqual(consoleErrorArg.message, 'message')
+        assert.strictEqual(typeof consoleErrorArg, 'string')
+        assert.strictEqual(consoleErrorArg, 'message')
       })
 
       it('should only log once for a given code', () => {