Skip to content

Commit

Permalink
Improve claim-backend logging (#64)
Browse files Browse the repository at this point in the history
* Added log4js logging

* Logger as functions

* Change default logging level to info. RPC Response has `info` level

* Formatting

---------

Co-authored-by: shuse2 <[email protected]>
  • Loading branch information
Phanco and shuse2 authored Jun 7, 2024
1 parent b6abc28 commit e2fda1f
Show file tree
Hide file tree
Showing 7 changed files with 185 additions and 22 deletions.
1 change: 1 addition & 0 deletions packages/claim-backend/.env.example
Original file line number Diff line number Diff line change
@@ -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
Expand Down
45 changes: 31 additions & 14 deletions packages/claim-backend/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down Expand Up @@ -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.
1 change: 1 addition & 0 deletions packages/claim-backend/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down
6 changes: 5 additions & 1 deletion packages/claim-backend/src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand All @@ -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'));
Expand All @@ -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}`);
});
})();
114 changes: 114 additions & 0 deletions packages/claim-backend/src/logger.ts
Original file line number Diff line number Diff line change
@@ -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<ServerParams>(
next: JSONRPCServerMiddlewareNext<ServerParams>,
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<ServerParams>(
next: JSONRPCServerMiddlewareNext<ServerParams>,
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;
11 changes: 6 additions & 5 deletions packages/claim-backend/src/utils/leaf-map.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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) {
Expand All @@ -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() {
Expand All @@ -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`);
}
29 changes: 27 additions & 2 deletions yarn.lock
Original file line number Diff line number Diff line change
Expand Up @@ -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==

[email protected]:
version "2.6.9"
resolved "https://registry.yarnpkg.com/debug/-/debug-2.6.9.tgz#5d128515df134ff327e90a4c93f4e077a536341f"
Expand Down Expand Up @@ -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==
Expand All @@ -3863,7 +3868,7 @@ [email protected]:
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==
Expand Down Expand Up @@ -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"
Expand Down Expand Up @@ -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"
Expand Down

0 comments on commit e2fda1f

Please sign in to comment.