Skip to content

Commit

Permalink
Merge pull request #1813 from bluesky-social/eric/app-903-extract-log…
Browse files Browse the repository at this point in the history
…ger-into-singleton

Add new logger
  • Loading branch information
estrattonbailey authored Nov 4, 2023
2 parents 46c2564 + 0c76866 commit e49a3d8
Show file tree
Hide file tree
Showing 70 changed files with 1,109 additions and 176 deletions.
2 changes: 2 additions & 0 deletions .env.example
Original file line number Diff line number Diff line change
@@ -1 +1,3 @@
SENTRY_AUTH_TOKEN=
EXPO_PUBLIC_LOG_LEVEL=debug
EXPO_PUBLIC_LOG_DEBUG=
22 changes: 12 additions & 10 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -13,21 +13,21 @@
"start": "expo start --dev-client",
"start:prod": "expo start --dev-client --no-dev --minify",
"clean-cache": "rm -rf node_modules/.cache/babel-loader/*",
"test": "jest --forceExit --testTimeout=20000 --bail",
"test-watch": "jest --watchAll",
"test-ci": "jest --ci --forceExit --reporters=default --reporters=jest-junit",
"test-coverage": "jest --coverage",
"test": "NODE_ENV=test jest --forceExit --testTimeout=20000 --bail",
"test-watch": "NODE_ENV=test jest --watchAll",
"test-ci": "NODE_ENV=test jest --ci --forceExit --reporters=default --reporters=jest-junit",
"test-coverage": "NODE_ENV=test jest --coverage",
"lint": "eslint ./src --ext .js,.jsx,.ts,.tsx",
"typecheck": "tsc --project ./tsconfig.check.json",
"e2e:mock-server": "./jest/dev-infra/with-test-redis-and-db.sh ts-node __e2e__/mock-server.ts",
"e2e:metro": "RN_SRC_EXT=e2e.ts,e2e.tsx expo run:ios",
"e2e:build": "detox build -c ios.sim.debug",
"e2e:run": "detox test --configuration ios.sim.debug --take-screenshots all",
"perf:test": "maestro test",
"perf:test:run": "maestro test __e2e__/maestro/scroll.yaml",
"perf:test:measure": "flashlight test --bundleId xyz.blueskyweb.app --testCommand 'yarn perf:test' --duration 150000 --resultsFilePath .perf/results.json",
"perf:test:results": "flashlight report .perf/results.json",
"perf:measure": "flashlight measure",
"perf:test": "NODE_ENV=test maestro test",
"perf:test:run": "NODE_ENV=test maestro test __e2e__/maestro/scroll.yaml",
"perf:test:measure": "NODE_ENV=test flashlight test --bundleId xyz.blueskyweb.app --testCommand 'yarn perf:test' --duration 150000 --resultsFilePath .perf/results.json",
"perf:test:results": "NODE_ENV=test flashlight report .perf/results.json",
"perf:measure": "NODE_ENV=test flashlight measure",
"build:apk": "eas build -p android --profile dev-android-apk"
},
"dependencies": {
Expand Down Expand Up @@ -80,6 +80,7 @@
"babel-plugin-transform-remove-console": "^6.9.4",
"base64-js": "^1.5.1",
"bcp-47-match": "^2.0.3",
"date-fns": "^2.30.0",
"email-validator": "^2.0.4",
"emoji-mart": "^5.5.2",
"eventemitter3": "^5.0.1",
Expand Down Expand Up @@ -118,6 +119,7 @@
"mobx": "^6.6.1",
"mobx-react-lite": "^3.4.0",
"mobx-utils": "^6.0.6",
"nanoid": "^5.0.2",
"normalize-url": "^8.0.0",
"patch-package": "^6.5.1",
"postinstall-postinstall": "^2.1.0",
Expand Down Expand Up @@ -240,7 +242,7 @@
"\\.[jt]sx?$": "babel-jest"
},
"transformIgnorePatterns": [
"node_modules/(?!((jest-)?react-native|@react-native(-community)?)|expo(nent)?|@expo(nent)?/.*|@expo-google-fonts/.*|react-navigation|@react-navigation/.*|@unimodules/.*|unimodules|sentry-expo|native-base|normalize-url|react-native-svg|@sentry/.*|sentry-expo|bcp-47-match)"
"node_modules/(?!((jest-)?react-native|@react-native(-community)?)|expo(nent)?|@expo(nent)?/.*|@expo-google-fonts/.*|react-navigation|nanoid|@react-navigation/.*|@unimodules/.*|unimodules|sentry-expo|native-base|normalize-url|react-native-svg|@sentry/.*|sentry-expo|bcp-47-match)"
],
"modulePathIgnorePatterns": [
"__tests__/.*/__mocks__",
Expand Down
9 changes: 9 additions & 0 deletions src/env.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
export const IS_TEST = process.env.NODE_ENV === 'test'
export const IS_DEV = __DEV__
export const IS_PROD = !IS_DEV
export const LOG_DEBUG = process.env.EXPO_PUBLIC_LOG_DEBUG || ''
export const LOG_LEVEL = (process.env.EXPO_PUBLIC_LOG_LEVEL || 'info') as
| 'debug'
| 'info'
| 'warn'
| 'error'
7 changes: 3 additions & 4 deletions src/lib/api/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -178,10 +178,9 @@ export async function post(store: RootStoreModel, opts: PostOpts) {
) {
encoding = 'image/jpeg'
} else {
store.log.warn(
'Unexpected image format for thumbnail, skipping',
opts.extLink.localThumb.path,
)
store.log.warn('Unexpected image format for thumbnail, skipping', {
thumbnail: opts.extLink.localThumb.path,
})
}
if (encoding) {
const thumbUploadRes = await uploadBlob(
Expand Down
4 changes: 2 additions & 2 deletions src/lib/hooks/useFollowProfile.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ export function useFollowProfile(profile: AppBskyActorDefs.ProfileViewBasic) {
following: false,
}
} catch (e: any) {
store.log.error('Failed to delete follow', e)
store.log.error('Failed to delete follow', {error: e})
throw e
}
} else if (state === FollowState.NotFollowing) {
Expand All @@ -40,7 +40,7 @@ export function useFollowProfile(profile: AppBskyActorDefs.ProfileViewBasic) {
following: true,
}
} catch (e: any) {
store.log.error('Failed to create follow', e)
store.log.error('Failed to create follow', {error: e})
throw e
}
}
Expand Down
12 changes: 6 additions & 6 deletions src/lib/hooks/useOTAUpdate.ts
Original file line number Diff line number Diff line change
Expand Up @@ -34,18 +34,18 @@ export function useOTAUpdate() {
// show a popup modal
showUpdatePopup()
} catch (e) {
console.error('useOTAUpdate: Error while checking for update', e)
store.log.error('useOTAUpdate: Error while checking for update', e)
store.log.error('useOTAUpdate: Error while checking for update', {
error: e,
})
}
}, [showUpdatePopup, store.log])
const updateEventListener = useCallback(
(event: Updates.UpdateEvent) => {
store.log.debug('useOTAUpdate: Listening for update...')
if (event.type === Updates.UpdateEventType.ERROR) {
store.log.error(
'useOTAUpdate: Error while listening for update',
event.message,
)
store.log.error('useOTAUpdate: Error while listening for update', {
message: event.message,
})
} else if (event.type === Updates.UpdateEventType.NO_UPDATE_AVAILABLE) {
// Handle no update available
// do nothing
Expand Down
19 changes: 9 additions & 10 deletions src/lib/notifications/notifications.ts
Original file line number Diff line number Diff line change
Expand Up @@ -30,18 +30,18 @@ export function init(store: RootStoreModel) {
appId: 'xyz.blueskyweb.app',
})
store.log.debug('Notifications: Sent push token (init)', {
type: token.type,
tokenType: token.type,
token: token.data,
})
} catch (error) {
store.log.error('Notifications: Failed to set push token', error)
store.log.error('Notifications: Failed to set push token', {error})
}
}

// listens for new changes to the push token
// In rare situations, a push token may be changed by the push notification service while the app is running. When a token is rolled, the old one becomes invalid and sending notifications to it will fail. A push token listener will let you handle this situation gracefully by registering the new token with your backend right away.
Notifications.addPushTokenListener(async ({data: t, type}) => {
store.log.debug('Notifications: Push token changed', {t, type})
store.log.debug('Notifications: Push token changed', {t, tokenType: type})
if (t) {
try {
await store.agent.api.app.bsky.notification.registerPush({
Expand All @@ -51,19 +51,19 @@ export function init(store: RootStoreModel) {
appId: 'xyz.blueskyweb.app',
})
store.log.debug('Notifications: Sent push token (event)', {
type,
tokenType: type,
token: t,
})
} catch (error) {
store.log.error('Notifications: Failed to set push token', error)
store.log.error('Notifications: Failed to set push token', {error})
}
}
})
})

// handle notifications that are received, both in the foreground or background
Notifications.addNotificationReceivedListener(event => {
store.log.debug('Notifications: received', event)
store.log.debug('Notifications: received', {event})
if (event.request.trigger.type === 'push') {
// refresh notifications in the background
store.me.notifications.syncQueue()
Expand All @@ -84,10 +84,9 @@ export function init(store: RootStoreModel) {
// handle notifications that are tapped on
const sub = Notifications.addNotificationResponseReceivedListener(
response => {
store.log.debug(
'Notifications: response received',
response.actionIdentifier,
)
store.log.debug('Notifications: response received', {
actionIdentifier: response.actionIdentifier,
})
if (
response.actionIdentifier === Notifications.DEFAULT_ACTION_IDENTIFIER
) {
Expand Down
99 changes: 99 additions & 0 deletions src/logger/README.md
Original file line number Diff line number Diff line change
@@ -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`._
36 changes: 36 additions & 0 deletions src/logger/__tests__/logDump.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,36 @@
import {expect, test} from '@jest/globals'

import {ConsoleTransportEntry, LogLevel} from '#/logger'
import {add, getEntries} from '#/logger/logDump'

test('works', () => {
const items: ConsoleTransportEntry[] = [
{
id: '1',
level: LogLevel.Debug,
message: 'hello',
metadata: {},
timestamp: Date.now(),
},
{
id: '2',
level: LogLevel.Debug,
message: 'hello',
metadata: {},
timestamp: Date.now(),
},
{
id: '3',
level: LogLevel.Debug,
message: 'hello',
metadata: {},
timestamp: Date.now(),
},
]

for (const item of items) {
add(item)
}

expect(getEntries()).toEqual(items.reverse())
})
Loading

0 comments on commit e49a3d8

Please sign in to comment.