diff --git a/packages/claim-backend/.env.example b/packages/claim-backend/.env.example index 589321a..6668c20 100644 --- a/packages/claim-backend/.env.example +++ b/packages/claim-backend/.env.example @@ -1,5 +1,6 @@ BACKEND_HOST=0.0.0.0 BACKEND_PORT=3000 +BACKEND_LOGGER_LEVEL=info DB_PORT=5432 DB_HOST=127.0.0.1 DB_DATABASE=claim-backend diff --git a/packages/claim-backend/README.md b/packages/claim-backend/README.md index 36b94eb..915ac33 100644 --- a/packages/claim-backend/README.md +++ b/packages/claim-backend/README.md @@ -11,20 +11,21 @@ Apart from Node version 18, Claim Backend also requires: ## .env Params -| param | Description | Required | -| ---------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------- | -| BACKEND_HOST | IP used by backend (Default: 127.0.0.1) | false | -| BACKEND_PORT | Port used by backend (Default: 3000) | false | -| DB_PORT | Port used by PostgreSQL DB (Default: 5432) | false | -| DB_HOST | Host used by PostgreSQL DB (Default: 127.0.0.1) | false | -| DB_DATABASE | Name of Database of PostgreSQL DB (Default: claim-backend) | false | -| DB_USERNAME | Username of PostgreSQL DB (Default: claim-backend) | false | -| DB_PASSWORD_PATH | Absolute file path or file path relative to `docker-compose.yaml` that stores the password of database of PostgreSQL DB (Default: ./db_password.txt) | false | -| DB_SSLMODE | A flag to turn on SSL Connection on DB (Default: false) | false | -| DB_SSL_CERT_PATH | Path to SSL Certificate (.crt or .pem) (Default: `null`) | When `DB_SSLMODE` is True | -| DB_LOGGING | A flag to turn on verbose logging of DB (Default: true) | false | -| CORS_ORIGIN | Accepted Origin, can be string or Regex (Default: \*) | false | -| MERKLE_TREE_PATH | Path merkle-tree-details.json, generated by Tree Builder | true | +| param | Description | Required | +| -------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------- | +| BACKEND_HOST | IP used by backend (Default: 127.0.0.1) | false | +| BACKEND_PORT | Port used by backend (Default: 3000) | false | +| BACKEND_LOGGER_LEVEL | Logger level in backend (trace/debug/info/warn/error/fatal) (Default: info) | false | +| DB_PORT | Port used by PostgreSQL DB (Default: 5432) | false | +| DB_HOST | Host used by PostgreSQL DB (Default: 127.0.0.1) | false | +| DB_DATABASE | Name of Database of PostgreSQL DB (Default: claim-backend) | false | +| DB_USERNAME | Username of PostgreSQL DB (Default: claim-backend) | false | +| DB_PASSWORD_PATH | Absolute file path or file path relative to `docker-compose.yaml` that stores the password of database of PostgreSQL DB (Default: ./db_password.txt) | false | +| DB_SSLMODE | A flag to turn on SSL Connection on DB (Default: false) | false | +| DB_SSL_CERT_PATH | Path to SSL Certificate (.crt or .pem) (Default: `null`) | When `DB_SSLMODE` is True | +| DB_LOGGING | A flag to turn on verbose logging of DB (Default: true) | false | +| CORS_ORIGIN | Accepted Origin, can be string or Regex (Default: \*) | false | +| MERKLE_TREE_PATH | Path merkle-tree-details.json, generated by Tree Builder | true | ## Run @@ -152,3 +153,19 @@ curl --location 'http://127.0.0.1:3000/rpc' \ } } ``` + +## Logging + +Claim Backend uses [log4js](https://www.npmjs.com/package/log4js) to record API call logs. 3 categories of logs will be used: + +- default + - `INFO`: General logging during the start of backend. +- RPC + - `INFO`: When sending success RPC response to client. + - `WARN`: When sending an Error RPC response to client, e.g. Invalid LSK address is queried. +- HTTP + - `DEBUG`: When there is a valid incoming HTTP request. + - `WARN`: When there is an error in clients' incoming HTTP request, e.g. Incorrect Json format. + - `ERROR`: When there is uncaught error on backend side. + +By setting `BACKEND_LOGGER_LEVEL`, it is possible to adjust which level of logging should be recorded. diff --git a/packages/claim-backend/package.json b/packages/claim-backend/package.json index be4465b..c306e06 100644 --- a/packages/claim-backend/package.json +++ b/packages/claim-backend/package.json @@ -34,6 +34,7 @@ "ethers": "^6.10.0", "express": "^4.19.2", "json-rpc-2.0": "^1.7.0", + "log4js": "^6.9.1", "pg": "^8.11.3", "reflect-metadata": "^0.2.1", "sequelize": "^6.28.0", diff --git a/packages/claim-backend/src/index.ts b/packages/claim-backend/src/index.ts index feb2e45..32dbf08 100644 --- a/packages/claim-backend/src/index.ts +++ b/packages/claim-backend/src/index.ts @@ -7,6 +7,7 @@ import { loadAirdropMerkleTree, loadMerkleTree } from './utils/leaf-map'; import { submitMultisig } from './controllers/submit-multisig'; import { checkEligibility } from './controllers/check-eligibility'; import { checkAirdropEligibility } from './controllers/check-airdrop-eligibility'; +import logger, { expressLogger, expressErrorHandler, rpcLogger, rpcErrorHandler } from './logger'; dotenv.config(); const HOST = process.env.BACKEND_HOST || '127.0.0.1'; @@ -25,10 +26,13 @@ void (async () => { app.use(cors(corsOptions)); app.use(express.json()); app.use(express.urlencoded({ extended: true })); + app.use(expressLogger); + app.use(expressErrorHandler); server.addMethod('checkEligibility', checkEligibility); server.addMethod('checkAirdropEligibility', checkAirdropEligibility); server.addMethod('submitMultisig', submitMultisig); + server.applyMiddleware(rpcLogger, rpcErrorHandler); // For Health Check from VPS monitoring app.get('/', (_, res) => res.send('OK')); @@ -49,6 +53,6 @@ void (async () => { await db.sync(); app.listen(PORT, HOST, () => { - console.info(`Claim Backend running at ${HOST}:${PORT}`); + logger.info(`Claim Backend running at ${HOST}:${PORT}`); }); })(); diff --git a/packages/claim-backend/src/logger.ts b/packages/claim-backend/src/logger.ts new file mode 100644 index 0000000..1cfbefb --- /dev/null +++ b/packages/claim-backend/src/logger.ts @@ -0,0 +1,114 @@ +import dotenv from 'dotenv'; +import { NextFunction, Request, Response } from 'express'; +import log4js from 'log4js'; +import { + JSONRPCRequest, + JSONRPCServerMiddlewareNext, + createJSONRPCErrorResponse, + JSONRPCResponse, + JSONRPCErrorCode, +} from 'json-rpc-2.0'; +import { ErrorCode } from './utils/error'; +dotenv.config(); + +const logger = log4js.getLogger(); +logger.level = process.env.BACKEND_LOGGER_LEVEL ?? 'info'; + +export const TRUNCATE_LENGTH = 150; + +export function truncate(text: string): string { + if (text.length > TRUNCATE_LENGTH) { + return text.substring(0, TRUNCATE_LENGTH) + ' ...'; + } + return text; +} + +export function formatRequest(request: JSONRPCRequest): string { + const method = request.method ?? 'EMPTY_METHOD'; + const params = request.params ?? {}; + + return `${method}:${truncate(JSON.stringify(params))}`; +} + +function expressLog(req: Request, res: Response, next: NextFunction, error: Error | null = null) { + const logger = log4js.getLogger('HTTP'); + const header = + ':remote-addr - ":method :url HTTP/:http-version" :status :content-length ":referrer" ":user-agent" :response-time'; + + let level = 'debug'; + let getMessage = (req: Request) => `${header} "${truncate(JSON.stringify(req.body))}"`; + if (error) { + if (error.message) { + level = 'warn'; + getMessage = () => `${header} "${error.message}"`; + } else { + logger.error(`Error Occurred: ${JSON.stringify(error)}`); + } + } + + return log4js.connectLogger(logger, { + level, + format: (req: Request, _res: Response, formatter: (str: string) => string) => { + return formatter(getMessage(req)); + }, + })(req, res, next); +} + +export function expressLogger(req: Request, res: Response, next: NextFunction) { + return expressLog(req, res, next); +} + +export function expressErrorHandler(error: Error, req: Request, res: Response, next: NextFunction) { + return expressLog(req, res, next, error); +} + +export async function rpcLogger( + next: JSONRPCServerMiddlewareNext, + request: JSONRPCRequest, + serverParams: ServerParams, +) { + const logger = log4js.getLogger('RPC'); + return next(request, serverParams).then((response: JSONRPCResponse | null) => { + if (!response) { + return response; + } + + const message = `Request ${formatRequest(request)} | Response ${truncate(JSON.stringify(response))}`; + if (response.error) { + logger.warn(message); + } else { + logger.info(message); + } + return response; + }); +} + +export async function rpcErrorHandler( + next: JSONRPCServerMiddlewareNext, + request: JSONRPCRequest, + serverParams: ServerParams, +) { + try { + return await next(request, serverParams); + } catch (error) { + if (error instanceof Error) { + if (Object.values(ErrorCode).includes(error.message as ErrorCode)) { + return createJSONRPCErrorResponse( + request.id ?? null, + JSONRPCErrorCode.InvalidRequest, + error.message, + ); + } + // Other RPC Error has been handled by library + return createJSONRPCErrorResponse( + request.id ?? null, + JSONRPCErrorCode.InternalError, + error.message, + ); + } else { + throw error; + } + } +} + +export default logger; diff --git a/packages/claim-backend/src/utils/leaf-map.ts b/packages/claim-backend/src/utils/leaf-map.ts index ea649c1..a3a316c 100644 --- a/packages/claim-backend/src/utils/leaf-map.ts +++ b/packages/claim-backend/src/utils/leaf-map.ts @@ -2,6 +2,7 @@ import { AirdropLeaf, Leaf } from '../interface'; import { address } from '@liskhq/lisk-cryptography'; import { remove0x } from './index'; import { readJson } from './fs-helper'; +import logger from '../logger'; const leafMap: { [lskAddress: string]: Leaf; @@ -33,7 +34,7 @@ export async function loadMerkleTree() { `MERKLE_TREE_PATH is invalid or does not exist: ${process.env.MERKLE_TREE_PATH}`, ); } - console.log(`Loading Merkle Tree: ${process.env.MERKLE_TREE_PATH}`); + logger.log(`Loading Merkle Tree: ${process.env.MERKLE_TREE_PATH}`); const { leaves } = await readJson(process.env.MERKLE_TREE_PATH); for (const leaf of leaves) { @@ -49,8 +50,8 @@ export async function loadMerkleTree() { } } - console.log(`LeafMap: ${Object.keys(leafMap).length} Leaves loaded`); - console.log(`MultisigMap: ${Object.keys(multisigMap).length} Multisig Account Holders loaded`); + logger.log(`LeafMap: ${Object.keys(leafMap).length} Leaves loaded`); + logger.log(`MultisigMap: ${Object.keys(multisigMap).length} Multisig Account Holders loaded`); } export async function loadAirdropMerkleTree() { @@ -60,12 +61,12 @@ export async function loadAirdropMerkleTree() { `AIRDROP_MERKLE_TREE_PATH is invalid or does not exist: ${airdropMerkleTreePath}`, ); } - console.log(`Loading Airdrop Merkle Tree: ${airdropMerkleTreePath}`); + logger.log(`Loading Airdrop Merkle Tree: ${airdropMerkleTreePath}`); const { leaves } = await readJson(airdropMerkleTreePath); for (const leaf of leaves) { airdropLeafMap[leaf.lskAddress] = leaf; } - console.log(`AirdropLeafMap: ${Object.keys(airdropLeafMap).length} Leaves loaded`); + logger.log(`AirdropLeafMap: ${Object.keys(airdropLeafMap).length} Leaves loaded`); } diff --git a/yarn.lock b/yarn.lock index 367fac9..1227a0c 100644 --- a/yarn.lock +++ b/yarn.lock @@ -2962,6 +2962,11 @@ data-view-byte-offset@^1.0.0: es-errors "^1.3.0" is-data-view "^1.0.1" +date-format@^4.0.14: + version "4.0.14" + resolved "https://registry.yarnpkg.com/date-format/-/date-format-4.0.14.tgz#7a8e584434fb169a521c8b7aa481f355810d9400" + integrity sha512-39BOQLs9ZjKh0/patS9nrT8wc3ioX3/eA/zgbKNopnF2wCqJEoxywwwElATYvRsXdnOxA/OQeQoFZ3rFjVajhg== + debug@2.6.9: version "2.6.9" resolved "https://registry.yarnpkg.com/debug/-/debug-2.6.9.tgz#5d128515df134ff327e90a4c93f4e077a536341f" @@ -3836,7 +3841,7 @@ flat@^5.0.2: resolved "https://registry.yarnpkg.com/flat/-/flat-5.0.2.tgz#8ca6fe332069ffa9d324c327198c598259ceb241" integrity sha512-b6suED+5/3rTpUBdG1gupIl8MPFCAMA0QXwmljLhvCUKcUvdE4gWky9zpuGCcXHOsz4J9wPGNWq6OKpmIzz3hQ== -flatted@^3.2.9: +flatted@^3.2.7, flatted@^3.2.9: version "3.3.1" resolved "https://registry.yarnpkg.com/flatted/-/flatted-3.3.1.tgz#21db470729a6734d4997002f439cb308987f567a" integrity sha512-X8cqMLLie7KsNUDSdzeN8FYK9rEt4Dt67OsG/DNGnYTSDBG4uFAJFBnUeiV+zCVAvwFy56IjM9sH51jVaEhNxw== @@ -3863,7 +3868,7 @@ fresh@0.5.2: resolved "https://registry.yarnpkg.com/fresh/-/fresh-0.5.2.tgz#3d8cadd90d976569fa835ab1f8e4b23a105605a7" integrity sha512-zJ2mQYM18rEFOudeV4GShTGIQ7RbzA7ozbU9I/XBpm7kqgMywgmylMwXHxZJmkVoYkna9d2pVXVXPdYTP9ej8Q== -fs-extra@^8.1: +fs-extra@^8.1, fs-extra@^8.1.0: version "8.1.0" resolved "https://registry.yarnpkg.com/fs-extra/-/fs-extra-8.1.0.tgz#49d43c45a88cd9677668cb7be1b46efdb8d2e1c0" integrity sha512-yhlQgA6mnOJUKOsRUFsgJdQCvkKhcz8tlZG5HBQfReYZy46OwLcY+Zia0mtdHsOo9y/hP+CxMN0TU9QxoOtG4g== @@ -4775,6 +4780,17 @@ log-update@^4.0.0: slice-ansi "^4.0.0" wrap-ansi "^6.2.0" +log4js@^6.9.1: + version "6.9.1" + resolved "https://registry.yarnpkg.com/log4js/-/log4js-6.9.1.tgz#aba5a3ff4e7872ae34f8b4c533706753709e38b6" + integrity sha512-1somDdy9sChrr9/f4UlzhdaGfDR2c/SaD2a4T7qEkG4jTS57/B3qmnjLYePwQ8cqWnUHZI0iAKxMBpCZICiZ2g== + dependencies: + date-format "^4.0.14" + debug "^4.3.4" + flatted "^3.2.7" + rfdc "^1.3.0" + streamroller "^3.1.5" + loupe@^2.3.6: version "2.3.7" resolved "https://registry.yarnpkg.com/loupe/-/loupe-2.3.7.tgz#6e69b7d4db7d3ab436328013d37d1c8c3540c697" @@ -6194,6 +6210,15 @@ stdout-stderr@^0.1.9: debug "^4.1.1" strip-ansi "^6.0.0" +streamroller@^3.1.5: + version "3.1.5" + resolved "https://registry.yarnpkg.com/streamroller/-/streamroller-3.1.5.tgz#1263182329a45def1ffaef58d31b15d13d2ee7ff" + integrity sha512-KFxaM7XT+irxvdqSP1LGLgNWbYN7ay5owZ3r/8t77p+EtSUAfUgtl7be3xtqtOmGUl9K9YPO2ca8133RlTjvKw== + dependencies: + date-format "^4.0.14" + debug "^4.3.4" + fs-extra "^8.1.0" + string-argv@^0.3.1: version "0.3.2" resolved "https://registry.yarnpkg.com/string-argv/-/string-argv-0.3.2.tgz#2b6d0ef24b656274d957d54e0a4bbf6153dc02b6"