diff --git a/backend/package.json b/backend/package.json index 1e2521af9..ca7189506 100644 --- a/backend/package.json +++ b/backend/package.json @@ -87,6 +87,7 @@ "sanitize-html": "~2.17.0", "slug": "~9.1.0", "trunc-html": "~1.1.2", + "tslog": "^4.9.3", "uuid": "~9.0.1", "validator": "^13.15.15", "xregexp": "^5.1.2" diff --git a/backend/src/config/index.ts b/backend/src/config/index.ts index 0aee79626..b8ccc382a 100644 --- a/backend/src/config/index.ts +++ b/backend/src/config/index.ts @@ -29,6 +29,7 @@ const environment = { ? (env.DISABLED_MIDDLEWARES?.split(',') ?? []) : [], SEND_MAIL: env.NODE_ENV !== 'test', + LOG_LEVEL: 'DEBUG', } const required = { diff --git a/backend/src/index.ts b/backend/src/index.ts index 612141733..481d95183 100644 --- a/backend/src/index.ts +++ b/backend/src/index.ts @@ -1,9 +1,12 @@ /* eslint-disable @typescript-eslint/restrict-template-expressions */ import CONFIG from './config' +import { loggerPlugin } from './plugins/apolloLogger' import createServer from './server' -const { server, httpServer } = createServer() +const { server, httpServer } = createServer({ + plugins: [loggerPlugin], +}) const url = new URL(CONFIG.GRAPHQL_URI) httpServer.listen({ port: url.port }, () => { /* eslint-disable-next-line no-console */ diff --git a/backend/src/logger.ts b/backend/src/logger.ts new file mode 100644 index 000000000..1d3f5f461 --- /dev/null +++ b/backend/src/logger.ts @@ -0,0 +1,63 @@ +import { ILogObj, Logger } from 'tslog' + +import CONFIG from './config' + +const { LOG_LEVEL } = CONFIG + +const logLevels = ['SILLY', 'TRACE', 'DEBUG', 'INFO', 'WARN', 'ERROR', 'FATAL'] as const +type LogLevel = (typeof logLevels)[number] + +function isLogLevel(level: string): level is LogLevel { + return logLevels.includes(level as LogLevel) +} + +if (!isLogLevel(LOG_LEVEL)) { + throw new Error(`Unknown log level '${LOG_LEVEL}'`) +} + +const logLevelsMap: Record = { + SILLY: 0, + TRACE: 1, + DEBUG: 2, + INFO: 3, + WARN: 4, + ERROR: 5, + FATAL: 6, +} + +const minLevel = logLevelsMap[LOG_LEVEL] // eslint-disable-line security/detect-object-injection + +/** + * The Singleton class defines the `getInstance` method that lets clients access + * the unique singleton instance. + */ +// eslint-disable-next-line @typescript-eslint/no-extraneous-class +class LoggerSingleton { + private static instance: Logger + + /** + * The Singleton's constructor should always be private to prevent direct + * construction calls with the `new` operator. + */ + // eslint-disable-next-line @typescript-eslint/no-empty-function + private constructor() {} + + /** + * The static method that controls the access to the singleton instance. + * + * This implementation let you subclass the Singleton class while keeping + * just one instance of each subclass around. + */ + public static getInstance(): Logger { + if (!LoggerSingleton.instance) { + LoggerSingleton.instance = new Logger({ minLevel, name: 'mainLogger' }) + } + + return LoggerSingleton.instance + } +} + +const logger = LoggerSingleton.getInstance() +export default logger +type OcelotLogger = typeof logger +export type { OcelotLogger as Logger } diff --git a/backend/src/plugins/apolloLogger.spec.ts b/backend/src/plugins/apolloLogger.spec.ts new file mode 100644 index 000000000..ea829ca82 --- /dev/null +++ b/backend/src/plugins/apolloLogger.spec.ts @@ -0,0 +1,89 @@ +/* eslint-disable @typescript-eslint/no-unsafe-call */ +/* eslint-disable @typescript-eslint/no-unsafe-member-access */ +/* eslint-disable @typescript-eslint/no-unsafe-return */ +import { ApolloServer } from 'apollo-server-express' +import { createTestClient } from 'apollo-server-testing' + +import databaseContext from '@context/database' +import Factory, { cleanDatabase } from '@db/factories' +import { loginMutation } from '@src/graphql/queries/loginMutation' +import ocelotLogger from '@src/logger' +import { loggerPlugin } from '@src/plugins/apolloLogger' +import createServer, { getContext } from '@src/server' + +const database = databaseContext() + +let server: ApolloServer + +let mutate, authenticatedUser + +beforeAll(async () => { + await cleanDatabase() + + // eslint-disable-next-line @typescript-eslint/require-await + const contextUser = async (_req) => authenticatedUser + const context = getContext({ user: contextUser, database }) + + server = createServer({ context, plugins: [loggerPlugin] }).server + + const createTestClientResult = createTestClient(server) + mutate = createTestClientResult.mutate +}) + +afterAll(async () => { + await cleanDatabase() + void server.stop() + void database.driver.close() + database.neode.close() +}) + +const loggerSpy = jest.spyOn(ocelotLogger, 'debug') +const consoleSpy = jest.spyOn(console, 'log') + +afterEach(async () => { + await cleanDatabase() +}) + +describe('apollo logger', () => { + beforeEach(async () => { + await Factory.build( + 'user', + { + id: 'user', + name: 'user', + slug: 'user', + }, + { + email: 'test@example.org', + password: '1234', + }, + ) + }) + + describe('login mutation', () => { + it('logs the request and response', async () => { + await mutate({ + mutation: loginMutation, + variables: { + email: 'test@example.org', + password: '1234', + }, + }) + + expect(loggerSpy).toBeCalledTimes(2) + expect(loggerSpy).toBeCalledWith( + 'Apollo Request', + expect.any(String), + '"mutation ($email: String!, $password: String!) {\\n login(email: $email, password: $password)\\n}\\n"', + JSON.stringify({ + email: 'test@example.org', + password: '***', + }), + ) + + expect(loggerSpy).toBeCalledWith('Apollo Response', expect.any(String), expect.any(String)) + + expect(consoleSpy).toBeCalledTimes(2) + }) + }) +}) diff --git a/backend/src/plugins/apolloLogger.ts b/backend/src/plugins/apolloLogger.ts new file mode 100644 index 000000000..d8bf0789a --- /dev/null +++ b/backend/src/plugins/apolloLogger.ts @@ -0,0 +1,39 @@ +/* eslint-disable @typescript-eslint/no-unsafe-member-access */ +/* eslint-disable @typescript-eslint/no-unsafe-assignment */ + +import { randomBytes } from 'node:crypto' + +import cloneDeep from 'lodash/cloneDeep' + +import ocelotLogger from '@src/logger' + +export const loggerPlugin = { + requestDidStart(requestContext) { + const isIntrospectionQuery = requestContext.request.operationName === 'IntrospectionQuery' + const qID = randomBytes(4).toString('hex') + if (!isIntrospectionQuery) { + const logRequest = ['Apollo Request', qID] + logRequest.push(JSON.stringify(requestContext.request.query)) + if (requestContext.request.variables) { + const variables = cloneDeep(requestContext.request.variables) + if (variables.password) variables.password = '***' + logRequest.push(JSON.stringify(variables)) + } + ocelotLogger.debug(...logRequest) + } + return { + // eslint-disable-next-line @typescript-eslint/require-await + async willSendResponse(requestContext) { + if (!isIntrospectionQuery) { + const logResponse = ['Apollo Response', qID] + if (requestContext.errors) { + ocelotLogger.error(...logResponse, JSON.stringify(requestContext.errors)) + return + } + logResponse.push(JSON.stringify(requestContext.response.data)) + ocelotLogger.debug(...logResponse) + } + }, + } + }, +} diff --git a/backend/src/server.ts b/backend/src/server.ts index f56b01f34..b5f183e32 100644 --- a/backend/src/server.ts +++ b/backend/src/server.ts @@ -19,9 +19,12 @@ import pubsubContext from '@context/pubsub' import CONFIG from './config' import schema from './graphql/schema' import decode from './jwt/decode' +import ocelotLogger from './logger' // eslint-disable-next-line import/no-cycle import middleware from './middleware' +import type OcelotLogger from './logger' + const serverDatabase = databaseContext() const serverPubsub = pubsubContext() @@ -33,11 +36,18 @@ export const getContext = database = serverDatabase, pubsub = serverPubsub, user = databaseUser, + logger = ocelotLogger, }: { database?: ReturnType pubsub?: ReturnType user?: (any) => Promise - } = { database: serverDatabase, pubsub: serverPubsub, user: databaseUser }, + logger?: typeof OcelotLogger + } = { + database: serverDatabase, + pubsub: serverPubsub, + user: databaseUser, + logger: ocelotLogger, + }, ) => async (req) => { const u = await user(req) @@ -46,6 +56,7 @@ export const getContext = driver: database.driver, neode: database.neode, pubsub, + logger, user: u, req, cypherParams: { @@ -54,6 +65,8 @@ export const getContext = } } +export type Context = Awaited>> + export const context = async (options) => { const { connection, req } = options if (connection) { @@ -79,6 +92,7 @@ const createServer = (options?) => { } return error }, + plugins: [], } const server = new ApolloServer(Object.assign(defaults, options)) @@ -103,4 +117,3 @@ const createServer = (options?) => { } export default createServer -export type Context = Awaited>> diff --git a/backend/yarn.lock b/backend/yarn.lock index f677b8d41..64bdafeb2 100644 --- a/backend/yarn.lock +++ b/backend/yarn.lock @@ -10252,14 +10252,7 @@ string_decoder@^1.1.1, string_decoder@^1.3.0: dependencies: safe-buffer "~5.2.0" -"strip-ansi-cjs@npm:strip-ansi@^6.0.1": - version "6.0.1" - resolved "https://registry.yarnpkg.com/strip-ansi/-/strip-ansi-6.0.1.tgz#9e26c63d30f53443e9489495b2105d37b67a85d9" - integrity sha512-Y38VPSHcqkFrCpFnQ9vuSXmquuv5oXOKpGeT6aGrr3o3Gc9AlVa6JBfUSOCnbxGGZF+/0ooI7KrPuUSztUdU5A== - dependencies: - ansi-regex "^5.0.1" - -strip-ansi@6.0.1, strip-ansi@^6.0.0, strip-ansi@^6.0.1, strip-ansi@^7.0.1: +"strip-ansi-cjs@npm:strip-ansi@^6.0.1", strip-ansi@6.0.1, strip-ansi@^6.0.0, strip-ansi@^6.0.1, strip-ansi@^7.0.1: version "6.0.1" resolved "https://registry.yarnpkg.com/strip-ansi/-/strip-ansi-6.0.1.tgz#9e26c63d30f53443e9489495b2105d37b67a85d9" integrity sha512-Y38VPSHcqkFrCpFnQ9vuSXmquuv5oXOKpGeT6aGrr3o3Gc9AlVa6JBfUSOCnbxGGZF+/0ooI7KrPuUSztUdU5A== @@ -10686,6 +10679,11 @@ tslib@^2.2.0, tslib@^2.4.0, tslib@^2.6.2: resolved "https://registry.yarnpkg.com/tslib/-/tslib-2.8.1.tgz#612efe4ed235d567e8aba5f2a5fab70280ade83f" integrity sha512-oJFu94HQb+KVduSUQL7wnpmqnfmLsOA/nAh6b6EH0wCEoK0/mPeXU6c3wKDV83MkOuHPRHtSXKKU99IBazS/2w== +tslog@^4.9.3: + version "4.9.3" + resolved "https://registry.yarnpkg.com/tslog/-/tslog-4.9.3.tgz#d4167d5f51748bdeab593945bc2d8f9827ea0dba" + integrity sha512-oDWuGVONxhVEBtschLf2cs/Jy8i7h1T+CpdkTNWQgdAF7DhRo2G8vMCgILKe7ojdEkLhICWgI1LYSSKaJsRgcw== + tsutils@^3.21.0: version "3.21.0" resolved "https://registry.yarnpkg.com/tsutils/-/tsutils-3.21.0.tgz#b48717d394cea6c1e096983eed58e9d61715b623" @@ -11221,16 +11219,7 @@ with@^7.0.0: assert-never "^1.2.1" babel-walk "3.0.0-canary-5" -"wrap-ansi-cjs@npm:wrap-ansi@^7.0.0": - version "7.0.0" - resolved "https://registry.yarnpkg.com/wrap-ansi/-/wrap-ansi-7.0.0.tgz#67e145cff510a6a6984bdf1152911d69d2eb9e43" - integrity sha512-YVGIj2kamLSTxw6NsZjoBxfSwsn0ycdesmc4p+Q21c5zPuZ1pl+NfxVdxPtdHvmNVOQ6XSYG4AUtyt/Fi7D16Q== - dependencies: - ansi-styles "^4.0.0" - string-width "^4.1.0" - strip-ansi "^6.0.0" - -wrap-ansi@7.0.0, wrap-ansi@^7.0.0, wrap-ansi@^8.1.0: +"wrap-ansi-cjs@npm:wrap-ansi@^7.0.0", wrap-ansi@7.0.0, wrap-ansi@^7.0.0, wrap-ansi@^8.1.0: version "7.0.0" resolved "https://registry.yarnpkg.com/wrap-ansi/-/wrap-ansi-7.0.0.tgz#67e145cff510a6a6984bdf1152911d69d2eb9e43" integrity sha512-YVGIj2kamLSTxw6NsZjoBxfSwsn0ycdesmc4p+Q21c5zPuZ1pl+NfxVdxPtdHvmNVOQ6XSYG4AUtyt/Fi7D16Q==