Add new logger

7 files changed, 837 insertions, 0 deletions

diff --git a/src/logger/README.md b/src/logger/README.md
new file mode 100644
index 000000000..1dfd5da23
--- /dev/null
+++ b/src/logger/README.md
@@ -0,0 +1,99 @@
+# Logger
+
+Simple logger for Bluesky. Supports log levels, debug contexts, and separate
+transports for production, dev, and test mode.
+
+## At a Glance
+
+```typescript
+import { logger } from '#/logger'
+
+logger.debug(message[, metadata, debugContext])
+logger.info(message[, metadata])
+logger.log(message[, metadata])
+logger.warn(message[, metadata])
+logger.error(error[, metadata])
+```
+
+#### Modes
+
+The "modes" referred to here are inferred from the values exported from `#/env`.
+Basically, the booleans `IS_DEV`, `IS_TEST`, and `IS_PROD`.
+
+#### Log Levels
+
+Log levels are used to filter which logs are either printed to the console
+and/or sent to Sentry and other reporting services. To configure, set the
+`EXPO_PUBLIC_LOG_LEVEL` environment variable in `.env` to one of `debug`,
+`info`, `log`, `warn`, or `error`.
+
+This variable should be `info` in production, and `debug` in dev. If it gets too
+noisy in dev, simply set it to a higher level, such as `warn`.
+
+## Usage
+
+```typescript
+import { logger } from '#/logger';
+```
+
+### `logger.error`
+
+The `error` level is for... well, errors. These are sent to Sentry in production mode.
+
+`error`, along with all log levels, supports an additional parameter, `metadata: Record<string, unknown>`. Use this to provide values to the [Sentry
+breadcrumb](https://docs.sentry.io/platforms/react-native/enriching-events/breadcrumbs/#manual-breadcrumbs).
+
+```typescript
+try {
+  // some async code
+} catch (e) {
+  logger.error(e, { ...metadata });
+}
+```
+
+### `logger.warn`
+
+Warnings will be sent to Sentry as a separate Issue with level `warning`, as
+well as as breadcrumbs, with a severity level of `warning`
+
+### `logger.log`
+
+Logs with level `log` will be sent to Sentry as a separate Issue with level `log`, as
+well as as breadcrumbs, with a severity level of `default`.
+
+### `logger.info`
+
+The `info` level should be used for information that would be helpful in a
+tracing context, like Sentry. In production mode, `info` logs are sent
+to Sentry as breadcrumbs, which decorate log levels above `info` such as `log`,
+`warn`, and `error`.
+
+### `logger.debug`
+
+Debug level is really only intended for local development. Use this instead of
+`console.log`.
+
+```typescript
+logger.debug(message, { ...metadata });
+```
+
+Inspired by [debug](https://www.npmjs.com/package/debug), when writing debug
+logs, you can optionally pass a _context_, which can be then filtered when in
+debug mode.
+
+This value should be related to the feature, component, or screen
+the code is running within, and **it should be defined in `#/logger/debugContext`**.
+This way we know if a relevant context already exists, and we can trace all
+active contexts in use in our app. This const enum is conveniently available on
+the `logger` at `logger.DebugContext`.
+
+For example, a debug log like this:
+
+```typescript
+logger.debug(message, {}, logger.DebugContext.composer);
+```
+
+Would be logged to the console in dev mode if `EXPO_PUBLIC_LOG_LEVEL=debug`, _or_ if you
+pass a separate environment variable `LOG_DEBUG=composer`. This variable supports
+multiple contexts using commas like `LOG_DEBUG=composer,profile`, and _automatically
+sets the log level to `debug`, regardless of `EXPO_PUBLIC_LOG_LEVEL`._
diff --git a/src/logger/__tests__/logger.test.ts b/src/logger/__tests__/logger.test.ts
new file mode 100644
index 000000000..46a5be610
--- /dev/null
+++ b/src/logger/__tests__/logger.test.ts
@@ -0,0 +1,424 @@
+import {nanoid} from 'nanoid/non-secure'
+import {jest, describe, expect, test, beforeAll} from '@jest/globals'
+import {Native as Sentry} from 'sentry-expo'
+
+import {Logger, LogLevel, sentryTransport} from '#/logger'
+
+jest.mock('#/env', () => ({
+  IS_TEST: true,
+  IS_DEV: false,
+  IS_PROD: false,
+  /*
+   * Forces debug mode for tests using the default logger. Most tests create
+   * their own logger instance.
+   */
+  LOG_LEVEL: 'debug',
+  LOG_DEBUG: '',
+}))
+
+jest.mock('sentry-expo', () => ({
+  Native: {
+    addBreadcrumb: jest.fn(),
+    captureException: jest.fn(),
+    captureMessage: jest.fn(),
+  },
+}))
+
+beforeAll(() => {
+  jest.useFakeTimers()
+})
+
+describe('general functionality', () => {
+  test('default params', () => {
+    const logger = new Logger()
+    expect(logger.enabled).toBeFalsy()
+    expect(logger.level).toEqual(LogLevel.Debug) // mocked above
+  })
+
+  test('can override default params', () => {
+    const logger = new Logger({
+      enabled: true,
+      level: LogLevel.Info,
+    })
+    expect(logger.enabled).toBeTruthy()
+    expect(logger.level).toEqual(LogLevel.Info)
+  })
+
+  test('disabled logger does not report', () => {
+    const logger = new Logger({
+      enabled: false,
+      level: LogLevel.Debug,
+    })
+
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+    logger.debug('message')
+
+    expect(mockTransport).not.toHaveBeenCalled()
+  })
+
+  test('disablement', () => {
+    const logger = new Logger({
+      enabled: true,
+      level: LogLevel.Debug,
+    })
+
+    logger.disable()
+
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+    logger.debug('message')
+
+    expect(mockTransport).not.toHaveBeenCalled()
+  })
+
+  test('passing debug contexts automatically enables debug mode', () => {
+    const logger = new Logger({debug: 'specific'})
+    expect(logger.level).toEqual(LogLevel.Debug)
+  })
+
+  test('supports extra metadata', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({enabled: true})
+
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+
+    const extra = {foo: true}
+    logger.warn('message', extra)
+
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Warn,
+      'message',
+      extra,
+      timestamp,
+    )
+  })
+
+  test('supports nullish/falsy metadata', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({enabled: true})
+
+    const mockTransport = jest.fn()
+
+    const remove = logger.addTransport(mockTransport)
+
+    // @ts-expect-error testing the JS case
+    logger.warn('a', null)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Warn,
+      'a',
+      {},
+      timestamp,
+    )
+
+    // @ts-expect-error testing the JS case
+    logger.warn('b', false)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Warn,
+      'b',
+      {},
+      timestamp,
+    )
+
+    // @ts-expect-error testing the JS case
+    logger.warn('c', 0)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Warn,
+      'c',
+      {},
+      timestamp,
+    )
+
+    remove()
+
+    logger.addTransport((level, message, metadata) => {
+      expect(typeof metadata).toEqual('object')
+    })
+
+    // @ts-expect-error testing the JS case
+    logger.warn('message', null)
+  })
+
+  test('sentryTransport', () => {
+    const message = 'message'
+    const timestamp = Date.now()
+    const sentryTimestamp = timestamp / 1000
+
+    sentryTransport(LogLevel.Debug, message, {}, timestamp)
+    expect(Sentry.addBreadcrumb).toHaveBeenCalledWith({
+      message,
+      data: {},
+      type: 'default',
+      level: LogLevel.Debug,
+      timestamp: sentryTimestamp,
+    })
+
+    sentryTransport(
+      LogLevel.Info,
+      message,
+      {type: 'info', prop: true},
+      timestamp,
+    )
+    expect(Sentry.addBreadcrumb).toHaveBeenCalledWith({
+      message,
+      data: {prop: true},
+      type: 'info',
+      level: LogLevel.Info,
+      timestamp: sentryTimestamp,
+    })
+
+    sentryTransport(LogLevel.Log, message, {}, timestamp)
+    expect(Sentry.addBreadcrumb).toHaveBeenCalledWith({
+      message,
+      data: {},
+      type: 'default',
+      level: 'debug', // Sentry bug, log becomes debug
+      timestamp: sentryTimestamp,
+    })
+    expect(Sentry.captureMessage).toHaveBeenCalledWith(message, {
+      level: 'log',
+      tags: undefined,
+      extra: {},
+    })
+
+    sentryTransport(LogLevel.Warn, message, {}, timestamp)
+    expect(Sentry.addBreadcrumb).toHaveBeenCalledWith({
+      message,
+      data: {},
+      type: 'default',
+      level: 'warning',
+      timestamp: sentryTimestamp,
+    })
+    expect(Sentry.captureMessage).toHaveBeenCalledWith(message, {
+      level: 'warning',
+      tags: undefined,
+      extra: {},
+    })
+
+    const e = new Error('error')
+    const tags = {
+      prop: 'prop',
+    }
+
+    sentryTransport(
+      LogLevel.Error,
+      e,
+      {
+        tags,
+        prop: true,
+      },
+      timestamp,
+    )
+
+    expect(Sentry.captureException).toHaveBeenCalledWith(e, {
+      tags,
+      extra: {
+        prop: true,
+      },
+    })
+  })
+
+  test('add/remove transport', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({enabled: true})
+    const mockTransport = jest.fn()
+
+    const remove = logger.addTransport(mockTransport)
+
+    logger.warn('warn')
+
+    remove()
+
+    logger.warn('warn')
+
+    // only called once bc it was removed
+    expect(mockTransport).toHaveBeenNthCalledWith(
+      1,
+      LogLevel.Warn,
+      'warn',
+      {},
+      timestamp,
+    )
+  })
+})
+
+describe('debug contexts', () => {
+  const mockTransport = jest.fn()
+
+  test('specific', () => {
+    const timestamp = Date.now()
+    const message = nanoid()
+    const logger = new Logger({
+      enabled: true,
+      debug: 'specific',
+    })
+
+    logger.addTransport(mockTransport)
+    logger.debug(message, {}, 'specific')
+
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Debug,
+      message,
+      {},
+      timestamp,
+    )
+  })
+
+  test('namespaced', () => {
+    const timestamp = Date.now()
+    const message = nanoid()
+    const logger = new Logger({
+      enabled: true,
+      debug: 'namespace*',
+    })
+
+    logger.addTransport(mockTransport)
+    logger.debug(message, {}, 'namespace')
+
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Debug,
+      message,
+      {},
+      timestamp,
+    )
+  })
+
+  test('ignores inactive', () => {
+    const timestamp = Date.now()
+    const message = nanoid()
+    const logger = new Logger({
+      enabled: true,
+      debug: 'namespace:foo:*',
+    })
+
+    logger.addTransport(mockTransport)
+    logger.debug(message, {}, 'namespace:bar:baz')
+
+    expect(mockTransport).not.toHaveBeenCalledWith(
+      LogLevel.Debug,
+      message,
+      {},
+      timestamp,
+    )
+  })
+})
+
+describe('supports levels', () => {
+  test('debug', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({
+      enabled: true,
+      level: LogLevel.Debug,
+    })
+    const message = nanoid()
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+
+    logger.debug(message)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Debug,
+      message,
+      {},
+      timestamp,
+    )
+
+    logger.info(message)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Info,
+      message,
+      {},
+      timestamp,
+    )
+
+    logger.warn(message)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Warn,
+      message,
+      {},
+      timestamp,
+    )
+
+    const e = new Error(message)
+    logger.error(e)
+    expect(mockTransport).toHaveBeenCalledWith(LogLevel.Error, e, {}, timestamp)
+  })
+
+  test('info', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({
+      enabled: true,
+      level: LogLevel.Info,
+    })
+    const message = nanoid()
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+
+    logger.debug(message)
+    expect(mockTransport).not.toHaveBeenCalled()
+
+    logger.info(message)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Info,
+      message,
+      {},
+      timestamp,
+    )
+  })
+
+  test('warn', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({
+      enabled: true,
+      level: LogLevel.Warn,
+    })
+    const message = nanoid()
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+
+    logger.debug(message)
+    expect(mockTransport).not.toHaveBeenCalled()
+
+    logger.info(message)
+    expect(mockTransport).not.toHaveBeenCalled()
+
+    logger.warn(message)
+    expect(mockTransport).toHaveBeenCalledWith(
+      LogLevel.Warn,
+      message,
+      {},
+      timestamp,
+    )
+  })
+
+  test('error', () => {
+    const timestamp = Date.now()
+    const logger = new Logger({
+      enabled: true,
+      level: LogLevel.Error,
+    })
+    const message = nanoid()
+    const mockTransport = jest.fn()
+
+    logger.addTransport(mockTransport)
+
+    logger.debug(message)
+    expect(mockTransport).not.toHaveBeenCalled()
+
+    logger.info(message)
+    expect(mockTransport).not.toHaveBeenCalled()
+
+    logger.warn(message)
+    expect(mockTransport).not.toHaveBeenCalled()
+
+    const e = new Error('original message')
+    logger.error(e)
+    expect(mockTransport).toHaveBeenCalledWith(LogLevel.Error, e, {}, timestamp)
+  })
+})
diff --git a/src/logger/debugContext.ts b/src/logger/debugContext.ts
new file mode 100644
index 000000000..658f4b18b
--- /dev/null
+++ b/src/logger/debugContext.ts
@@ -0,0 +1,10 @@
+/**
+ * *Do not import this directly.* Instead, use the shortcut reference `logger.DebugContext`.
+ *
+ * Add debug contexts here. Although convention typically calls for enums ito
+ * be capitalized, for parity with the `LOG_DEBUG` env var, please use all
+ * lowercase.
+ */
+export const DebugContext = {
+  // e.g. composer: 'composer'
+} as const
diff --git a/src/logger/index.ts b/src/logger/index.ts
new file mode 100644
index 000000000..28b720910
--- /dev/null
+++ b/src/logger/index.ts
@@ -0,0 +1,290 @@
+import format from 'date-fns/format'
+import {nanoid} from 'nanoid/non-secure'
+
+import {Sentry} from '#/logger/sentry'
+import * as env from '#/env'
+import {DebugContext} from '#/logger/debugContext'
+import {add} from '#/logger/logDump'
+
+export enum LogLevel {
+  Debug = 'debug',
+  Info = 'info',
+  Log = 'log',
+  Warn = 'warn',
+  Error = 'error',
+}
+
+type Transport = (
+  level: LogLevel,
+  message: string | Error,
+  metadata: Metadata,
+  timestamp: number,
+) => void
+
+/**
+ * A union of some of Sentry's breadcrumb properties as well as Sentry's
+ * `captureException` parameter, `CaptureContext`.
+ */
+type Metadata = {
+  /**
+   * Applied as Sentry breadcrumb types. Defaults to `default`.
+   *
+   * @see https://develop.sentry.dev/sdk/event-payloads/breadcrumbs/#breadcrumb-types
+   */
+  type?:
+    | 'default'
+    | 'debug'
+    | 'error'
+    | 'navigation'
+    | 'http'
+    | 'info'
+    | 'query'
+    | 'transaction'
+    | 'ui'
+    | 'user'
+
+  /**
+   * Passed through to `Sentry.captureException`
+   *
+   * @see https://github.com/getsentry/sentry-javascript/blob/903addf9a1a1534a6cb2ba3143654b918a86f6dd/packages/types/src/misc.ts#L65
+   */
+  tags?: {
+    [key: string]:
+      | number
+      | string
+      | boolean
+      | bigint
+      | symbol
+      | null
+      | undefined
+  }
+
+  /**
+   * Any additional data, passed through to Sentry as `extra` param on
+   * exceptions, or the `data` param on breadcrumbs.
+   */
+  [key: string]: unknown
+} & Parameters<typeof Sentry.captureException>[1]
+
+export type ConsoleTransportEntry = {
+  id: string
+  timestamp: number
+  level: LogLevel
+  message: string | Error
+  metadata: Metadata
+}
+
+const enabledLogLevels: {
+  [key in LogLevel]: LogLevel[]
+} = {
+  [LogLevel.Debug]: [
+    LogLevel.Debug,
+    LogLevel.Info,
+    LogLevel.Log,
+    LogLevel.Warn,
+    LogLevel.Error,
+  ],
+  [LogLevel.Info]: [LogLevel.Info, LogLevel.Log, LogLevel.Warn, LogLevel.Error],
+  [LogLevel.Log]: [LogLevel.Log, LogLevel.Warn, LogLevel.Error],
+  [LogLevel.Warn]: [LogLevel.Warn, LogLevel.Error],
+  [LogLevel.Error]: [LogLevel.Error],
+}
+
+/**
+ * Used in dev mode to nicely log to the console
+ */
+export const consoleTransport: Transport = (
+  level,
+  message,
+  metadata,
+  timestamp,
+) => {
+  const extra = Object.keys(metadata).length
+    ? ' ' + JSON.stringify(metadata, null, '  ')
+    : ''
+  const log = {
+    [LogLevel.Debug]: console.debug,
+    [LogLevel.Info]: console.info,
+    [LogLevel.Log]: console.log,
+    [LogLevel.Warn]: console.warn,
+    [LogLevel.Error]: console.error,
+  }[level]
+
+  log(`${format(timestamp, 'HH:mm:ss')} ${message.toString()}${extra}`)
+}
+
+export const sentryTransport: Transport = (
+  level,
+  message,
+  {type, tags, ...metadata},
+  timestamp,
+) => {
+  /**
+   * 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({
+      message,
+      data: metadata,
+      type: type || 'default',
+      level: severity,
+      timestamp: timestamp / 1000, // Sentry expects seconds
+    })
+
+    /**
+     * Send all higher levels with `captureMessage`, with appropriate severity
+     * level
+     */
+    if (level === 'error' || level === 'warn' || level === 'log') {
+      const messageLevel = ({
+        [LogLevel.Log]: 'log',
+        [LogLevel.Warn]: 'warning',
+        [LogLevel.Error]: 'error',
+      }[level] || 'log') as Sentry.Breadcrumb['level']
+
+      Sentry.captureMessage(message, {
+        level: messageLevel,
+        tags,
+        extra: metadata,
+      })
+    }
+  } else {
+    /**
+     * It's otherwise an Error and should be reported with captureException
+     */
+    Sentry.captureException(message, {
+      tags,
+      extra: metadata,
+    })
+  }
+}
+
+/**
+ * Main class. Defaults are provided in the constructor so that subclasses are
+ * technically possible, if we need to go that route in the future.
+ */
+export class Logger {
+  LogLevel = LogLevel
+  DebugContext = DebugContext
+
+  enabled: boolean
+  level: LogLevel
+  transports: Transport[] = []
+
+  protected debugContextRegexes: RegExp[] = []
+
+  constructor({
+    enabled = !env.IS_TEST,
+    level = env.LOG_LEVEL as LogLevel,
+    debug = env.LOG_DEBUG || '',
+  }: {
+    enabled?: boolean
+    level?: LogLevel
+    debug?: string
+  } = {}) {
+    this.enabled = enabled !== false
+    this.level = debug ? LogLevel.Debug : level ?? LogLevel.Info // default to info
+    this.debugContextRegexes = (debug || '').split(',').map(context => {
+      return new RegExp(context.replace(/[^\w:*]/, '').replace(/\*/g, '.*'))
+    })
+  }
+
+  debug(message: string, metadata: Metadata = {}, context?: string) {
+    if (context && !this.debugContextRegexes.find(reg => reg.test(context)))
+      return
+    this.transport(LogLevel.Debug, message, metadata)
+  }
+
+  info(message: string, metadata: Metadata = {}) {
+    this.transport(LogLevel.Info, message, metadata)
+  }
+
+  log(message: string, metadata: Metadata = {}) {
+    this.transport(LogLevel.Log, message, metadata)
+  }
+
+  warn(message: string, metadata: Metadata = {}) {
+    this.transport(LogLevel.Warn, message, metadata)
+  }
+
+  error(error: Error | string, metadata: Metadata = {}) {
+    this.transport(LogLevel.Error, error, metadata)
+  }
+
+  addTransport(transport: Transport) {
+    this.transports.push(transport)
+    return () => {
+      this.transports.splice(this.transports.indexOf(transport), 1)
+    }
+  }
+
+  disable() {
+    this.enabled = false
+  }
+
+  enable() {
+    this.enabled = true
+  }
+
+  protected transport(
+    level: LogLevel,
+    message: string | Error,
+    metadata: Metadata = {},
+  ) {
+    if (!this.enabled) return
+    if (!enabledLogLevels[this.level].includes(level)) return
+
+    const timestamp = Date.now()
+    const meta = metadata || {}
+
+    for (const transport of this.transports) {
+      transport(level, message, meta, timestamp)
+    }
+
+    add({
+      id: nanoid(),
+      timestamp,
+      level,
+      message,
+      metadata: meta,
+    })
+  }
+}
+
+/**
+ * Logger instance. See `@/logger/README` for docs.
+ *
+ * Basic usage:
+ *
+ *   `logger.debug(message[, metadata, debugContext])`
+ *   `logger.info(message[, metadata])`
+ *   `logger.warn(message[, metadata])`
+ *   `logger.error(error[, metadata])`
+ *   `logger.disable()`
+ *   `logger.enable()`
+ */
+export const logger = new Logger()
+
+/**
+ * Report to console in dev, Sentry in prod, nothing in test.
+ */
+if (env.IS_DEV && !env.IS_TEST) {
+  logger.addTransport(consoleTransport)
+
+  /**
+   * Uncomment this to test Sentry in dev
+   */
+  // logger.addTransport(sentryTransport);
+} else if (env.IS_PROD) {
+  logger.addTransport(sentryTransport)
+}
diff --git a/src/logger/logDump.ts b/src/logger/logDump.ts
new file mode 100644
index 000000000..777ff7772
--- /dev/null
+++ b/src/logger/logDump.ts
@@ -0,0 +1,12 @@
+import {ConsoleTransportEntry} from '#/logger'
+
+let entries: ConsoleTransportEntry[] = []
+
+export function add(entry: ConsoleTransportEntry) {
+  entries.unshift(entry)
+  entries = entries.slice(0, 50)
+}
+
+export function getEntries() {
+  return entries
+}
diff --git a/src/logger/sentry/index.ts b/src/logger/sentry/index.ts
new file mode 100644
index 000000000..a2ed8452d
--- /dev/null
+++ b/src/logger/sentry/index.ts
@@ -0,0 +1 @@
+export {Native as Sentry} from 'sentry-expo'
diff --git a/src/logger/sentry/index.web.ts b/src/logger/sentry/index.web.ts
new file mode 100644
index 000000000..072b997f4
--- /dev/null
+++ b/src/logger/sentry/index.web.ts
@@ -0,0 +1 @@
+export {Browser as Sentry} from 'sentry-expo'