Logger improvements (#7729)

* Remove enablement

* Refactor context and filtering

* Fix imports, simplify transports config

* Migrate usages of debug context

* Re-org, add colors and grouping to console logging

* Remove temp default context

* Remove manual prefix

* Move colorizing out of console transport body

* Reduce reuse

* Pass through context

* Ensure bitdrift is enabled in dev

* Enable Sentry on web only

* Clean up types

* Docs

* Format

* Update tests

* Clean up tests

* No positional args

* Revert Sentry changes

* Clean up context, use it, pass metadata through to Bitdrift

* Fix up debugging

* Clean up metadata before passing to Bitdrift

* Correct transports

* Reserve context prop on metadata and include in transports

* Update tests

src/logger/transports/bitdrift.ts

@@ -0,0 +1,30 @@
+import {
+  debug as bdDebug,
+  error as bdError,
+  info as bdInfo,
+  warn as bdWarn,
+} from '#/lib/bitdrift'
+import {LogLevel, Transport} from '#/logger/types'
+import {prepareMetadata} from '#/logger/util'
+
+const logFunctions = {
+  [LogLevel.Debug]: bdDebug,
+  [LogLevel.Info]: bdInfo,
+  [LogLevel.Log]: bdInfo,
+  [LogLevel.Warn]: bdWarn,
+  [LogLevel.Error]: bdError,
+} as const
+
+export const bitdriftTransport: Transport = (
+  level,
+  context,
+  message,
+  metadata,
+) => {
+  const log = logFunctions[level]
+  log(message.toString(), {
+    // match Sentry payload
+    context,
+    ...prepareMetadata(metadata),
+  })
+}

src/logger/transports/console.ts

@@ -0,0 +1,90 @@
+import format from 'date-fns/format'
+
+import {LogLevel, Transport} from '#/logger/types'
+import {prepareMetadata} from '#/logger/util'
+import {isWeb} from '#/platform/detection'
+
+/**
+ * Used in dev mode to nicely log to the console
+ */
+export const consoleTransport: Transport = (
+  level,
+  context,
+  message,
+  metadata,
+  timestamp,
+) => {
+  const hasMetadata = Object.keys(metadata).length
+  const colorize = withColor(
+    {
+      [LogLevel.Debug]: colors.magenta,
+      [LogLevel.Info]: colors.blue,
+      [LogLevel.Log]: colors.green,
+      [LogLevel.Warn]: colors.yellow,
+      [LogLevel.Error]: colors.red,
+    }[level],
+  )
+
+  let msg = `${colorize(format(timestamp, 'HH:mm:ss'))}`
+  if (context) {
+    msg += ` ${colorize(`(${context})`)}`
+  }
+  if (message) {
+    msg += ` ${message.toString()}`
+  }
+
+  if (isWeb) {
+    if (hasMetadata) {
+      console.groupCollapsed(msg)
+      console.log(metadata)
+      console.groupEnd()
+    } else {
+      console.log(msg)
+    }
+    if (message instanceof Error) {
+      // for stacktrace
+      console.error(message)
+    }
+  } else {
+    if (hasMetadata) {
+      msg += ` ${JSON.stringify(prepareMetadata(metadata), null, 2)}`
+    }
+    console.log(msg)
+    if (message instanceof Error) {
+      // for stacktrace
+      console.error(message)
+    }
+  }
+}
+
+/**
+ * Color handling copied from Kleur
+ *
+ * @see https://github.com/lukeed/kleur/blob/fa3454483899ddab550d08c18c028e6db1aab0e5/colors.mjs#L13
+ */
+const colors: {
+  [key: string]: [number, number]
+} = {
+  default: [0, 0],
+  blue: [36, 39],
+  green: [32, 39],
+  magenta: [35, 39],
+  red: [31, 39],
+  yellow: [33, 39],
+}
+
+function withColor([x, y]: [number, number]) {
+  const rgx = new RegExp(`\\x1b\\[${y}m`, 'g')
+  const open = `\x1b[${x}m`,
+    close = `\x1b[${y}m`
+
+  return function (txt: string) {
+    if (txt == null) return txt
+
+    return (
+      open +
+      (~('' + txt).indexOf(close) ? txt.replace(rgx, close + open) : txt) +
+      close
+    )
+  }
+}

src/logger/transports/sentry.ts

@@ -0,0 +1,102 @@
+import {isNetworkError} from '#/lib/strings/errors'
+import {Sentry} from '#/logger/sentry/lib'
+import {LogLevel, Transport} from '#/logger/types'
+import {prepareMetadata} from '#/logger/util'
+
+export const sentryTransport: Transport = (
+  level,
+  context,
+  message,
+  {type, tags, ...metadata},
+  timestamp,
+) => {
+  const meta = {
+    // match Bitdrift payload
+    context,
+    ...prepareMetadata(metadata),
+  }
+  let _tags = tags || {}
+  _tags = {
+    // use `category` to match breadcrumbs
+    category: context,
+    ...tags,
+  }
+
+  /**
+   * If a string, report a breadcrumb
+   */
+  if (typeof message === 'string') {
+    const severity = (
+      {
+        [LogLevel.Debug]: 'debug',
+        [LogLevel.Info]: 'info',
+        [LogLevel.Log]: 'log', // Sentry value here is undefined
+        [LogLevel.Warn]: 'warning',
+        [LogLevel.Error]: 'error',
+      } as const
+    )[level]
+
+    Sentry.addBreadcrumb({
+      category: context,
+      message,
+      data: meta,
+      type: type || 'default',
+      level: severity,
+      timestamp: timestamp / 1000, // Sentry expects seconds
+    })
+
+    // We don't want to send any network errors to sentry
+    if (isNetworkError(message)) {
+      return
+    }
+
+    /**
+     * Send all higher levels with `captureMessage`, with appropriate severity
+     * level
+     */
+    if (level === 'error' || level === 'warn' || level === 'log') {
+      // Defer non-critical messages so they're sent in a batch
+      queueMessageForSentry(message, {
+        level: severity,
+        tags: _tags,
+        extra: meta,
+      })
+    }
+  } else {
+    /**
+     * It's otherwise an Error and should be reported with captureException
+     */
+    Sentry.captureException(message, {
+      tags: _tags,
+      extra: meta,
+    })
+  }
+}
+
+const queuedMessages: [string, Parameters<typeof Sentry.captureMessage>[1]][] =
+  []
+let sentrySendTimeout: ReturnType<typeof setTimeout> | null = null
+
+function queueMessageForSentry(
+  message: string,
+  captureContext: Parameters<typeof Sentry.captureMessage>[1],
+) {
+  queuedMessages.push([message, captureContext])
+  if (!sentrySendTimeout) {
+    // Throttle sending messages with a leading delay
+    // so that we can get Sentry out of the critical path.
+    sentrySendTimeout = setTimeout(() => {
+      sentrySendTimeout = null
+      sendQueuedMessages()
+    }, 7000)
+  }
+}
+
+function sendQueuedMessages() {
+  while (queuedMessages.length > 0) {
+    const record = queuedMessages.shift()
+    if (record) {
+      Sentry.captureMessage(record[0], record[1])
+    }
+  }
+}