diff options
Diffstat (limited to 'src/logger')
-rw-r--r-- | src/logger/README.md | 99 | ||||
-rw-r--r-- | src/logger/__tests__/logger.test.ts | 424 | ||||
-rw-r--r-- | src/logger/debugContext.ts | 10 | ||||
-rw-r--r-- | src/logger/index.ts | 290 | ||||
-rw-r--r-- | src/logger/logDump.ts | 12 | ||||
-rw-r--r-- | src/logger/sentry/index.ts | 1 | ||||
-rw-r--r-- | src/logger/sentry/index.web.ts | 1 |
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' |