Skip to content

Commit

Permalink
feat(mojaloop/#2928): upgrade logger to central-services-logger (#148)
Browse files Browse the repository at this point in the history 
* feat: upgrade logger to central-services-logger

* chore: fix file

* chore(snapshot): 13.1.0-snapshot.0

* chore: deps

* chore: fix int tests

* chore: test

* chore: testing

* chore(snapshot): 13.1.0-snapshot.1

* chore: change

* chore: tests

* chore(snapshot): 13.1.0-snapshot.2

* chore(snapshot): 13.1.0-snapshot.3

* chore: support contextual logging

* chore: quiet debug health endpoint

* chore: ignore

* chore: dep update

* chore: format

* chore: snapshot logger

* chore(snapshot): 13.1.0-snapshot.4

* chore: bump logger

* chore: coverage

* chore: coverage

* Apply suggestions from code review

Co-authored-by: Miguel de Barros <miguel@debarros.me>

* chore: lint

Co-authored-by: Miguel de Barros <miguel@debarros.me>
  • Loading branch information
@kleyow @mdebarros
kleyow and mdebarros authored Nov 17, 2022
1 parent cdf2e34 commit 8a1573e
Show file tree
Hide file tree
Showing 16 changed files with 4,064 additions and 2,420 deletions.
5,452 changes: 3,524 additions & 1,928 deletions package-lock.json
View file

Large diffs are not rendered by default.

34 changes: 18 additions & 16 deletions package.json
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "mojaloop-simulator",
"version": "13.0.1",
"version": "13.1.0-snapshot.4",
"description": "A canonical test example implementation of the parties, transfers and quotes resources of the Mojaloop FSP Interoperability API",
"license": "Apache-2.0",
"main": "src/index.js",
Expand Down Expand Up @@ -36,8 +36,8 @@
"lint": "eslint ./src/",
"lint:fix": "eslint ./src/ --fix",
"test": "npm run test:unit",
"test:unit": "CONFIG_OVERRIDE=./example.env ava -c 1 './test/unit/**/*.test.js'",
"test:coverage-check": "CONFIG_OVERRIDE=./example.env nyc ava './test/unit/**/*.test.js'",
"test:unit": "CONFIG_OVERRIDE=./example.env ava -c 1 --serial './test/unit/**/*.test.js'",
"test:coverage-check": "CONFIG_OVERRIDE=./example.env nyc ava --serial './test/unit/**/*.test.js'",
"test:integration": "CONFIG_OVERRIDE=./example.env jest --config './jest.integration.config.js' --testMatch '**/test/integration/**/*.(test|spec).js' --runInBand",
"test:functional": "echo 'No test specified' && exit 1",
"audit:resolve": "resolve-audit --production",
Expand All @@ -49,40 +49,42 @@
"wait-4-docker": "node ./scripts/_wait4_all.js"
},
"dependencies": {
"@koa/cors": "3.4.1",
"ajv": "8.11.0",
"chance": "1.1.8",
"@koa/cors": "4.0.0",
"@mojaloop/central-services-logger": "11.1.0",
"ajv": "8.11.2",
"chance": "1.1.9",
"core-util-is": "1.0.3",
"dotenv": "16.0.2",
"joi": "17.6.0",
"dotenv": "16.0.3",
"joi": "17.7.0",
"json-rules-engine": "^6.1.2",
"json-schema-ref-parser": "^9.0.9",
"koa": "2.13.4",
"koa-body": "5.0.0",
"koa-body": "6.0.1",
"mustache": "4.2.0",
"node-fetch": "^2.6.6",
"openapi-jsonschema-parameters": "12.0.2",
"random-word-slugs": "^0.1.6",
"sqlite": "4.1.2",
"sqlite3": "5.0.11",
"sqlite3": "5.1.2",
"yamljs": "0.3.0"
},
"devDependencies": {
"@types/jest": "^29.0.0",
"@types/jest": "^29.2.3",
"ava": "^3.15.0",
"axios": "^0.27.2",
"axios": "^1.1.3",
"eslint": "^7.32.0",
"eslint-config-airbnb-base": "15.0.0",
"eslint-plugin-ava": "^13.2.0",
"eslint-plugin-import": "2.26.0",
"eslint-plugin-jest": "^27.0.2",
"husky": "8.0.1",
"jest": "^29.0.2",
"eslint-plugin-jest": "^27.1.5",
"husky": "8.0.2",
"jest": "^29.3.1",
"jest-junit": "^14.0.1",
"npm-audit-resolver": "^3.0.0-0",
"npm-check-updates": "16.1.0",
"npm-check-updates": "16.4.1",
"npm-run-all": "4.1.5",
"nyc": "15.1.0",
"sinon": "^14.0.2",
"standard-version": "^9.5.0",
"tap-xunit": "2.4.1",
"uuid": "9.0.0"
Expand Down
168 changes: 107 additions & 61 deletions src/index.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,15 +30,16 @@
/* istanbul ignore file */

const Koa = require('koa');
const koaBody = require('koa-body');
const koaBody = require('koa-body').default;
const { generateSlug } = require('random-word-slugs');
const yaml = require('yamljs');
const util = require('util');
const https = require('https');
const cors = require('@koa/cors');
const router = require('./lib/router');
const Validate = require('./lib/validate');
const { Logger, Transports, getStackOrInspect } = require('./lib/log/log');
const { getStackOrInspect } = require('./lib/log/log');
const Logger = require('@mojaloop/central-services-logger');
const RulesEngine = require('./lib/rules-engine');

const Config = require('./lib/config');
Expand Down Expand Up @@ -89,15 +90,23 @@ async function rewriteContentTypeHeader(ctx, next) {
await setConfig(process.env);
const conf = getConfig();


// Set up a logger for each running server
const space = Number(process.env.LOG_INDENT);
const transports = await Promise.all([
Transports.consoleDir(),
Transports.sqlite(process.env.SQLITE_LOG_FILE),
]);
const simLogger = new Logger({ context: { app: 'simulator' }, space, transports });
const reportLogger = new Logger({ context: { app: 'report' }, space, transports });
const testApiLogger = new Logger({ context: { app: 'test-api' }, space, transports });
const simLogger = Logger.child({
context: {
app: 'simulator'
}
});
const reportLogger = Logger.child({
context: {
app: 'report'
}
});
const testApiLogger = Logger.child({
context: {
app: 'test-api'
}
});

const rulesEngine = new RulesEngine({ logger: simLogger });

Expand Down Expand Up @@ -133,48 +142,76 @@ async function rewriteContentTypeHeader(ctx, next) {

// Add a log context for each request, log the receipt and handling thereof
simulator.use(async (ctx, next) => {
ctx.state.logger = simLogger.push({
request: {
id: generateSlug(4),
path: ctx.path,
method: ctx.method,
},
// Create new child for lifespan of request
ctx.state.logger = simLogger.child({
context: {
app: 'simulator',
request: {
id: generateSlug(4),
path: ctx.path,
method: ctx.method,
}
}

});
ctx.state.logger.push({ body: ctx.request.body }).log('Request received');
await next();

const { body, status } = ctx.response;
ctx.state.logger.push({ response: { body, status } }).log('Request processed');
if (ctx.path == '/' || ctx.path == '/health') {
ctx.state.logger.isDebugEnabled && ctx.state.logger.debug({'msg': 'Request received', body: ctx.request.body});

await next();

const { body, status } = ctx.response;
ctx.state.logger.isDebugEnabled && ctx.state.logger.debug({'msg': 'Request processed', body, status});
} else {
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request received', body: ctx.request.body});

await next();

const { body, status } = ctx.response;
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request processed', body, status});
}
});

report.use(async (ctx, next) => {
ctx.state.logger = reportLogger.push({
request: {
id: generateSlug(4),
path: ctx.path,
method: ctx.method,
},
// Create new child for lifespan of request
ctx.state.logger = reportLogger.child({
context: {
app: 'report',
request: {
id: generateSlug(4),
path: ctx.path,
method: ctx.method,
}
}

});
ctx.state.logger.push({ body: ctx.request.body }).log('Request received');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request received', body: ctx.request.body});

await next();

const { body, status } = ctx.response;
ctx.state.logger.push({ response: { body, status } }).log('Request processed');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request processed', body, status});
});

testApi.use(async (ctx, next) => {
ctx.state.logger = testApiLogger.push({
request: {
id: generateSlug(4),
path: ctx.path,
method: ctx.method
},
// Create new child for lifespan of request
ctx.state.logger = testApiLogger.child({
context: {
app: 'test-api',
request: {
id: generateSlug(4),
path: ctx.path,
method: ctx.method,
}
}

});
ctx.state.logger.push({ body: ctx.request.body }).log('Request received');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request received', body: ctx.request.body});

await next();

const { body, status } = ctx.response;
ctx.state.logger.push({ response: { body, status } }).log('Request processed');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request processed', body, status});
});

simulator.use(rewriteContentTypeHeader);
Expand All @@ -184,18 +221,24 @@ async function rewriteContentTypeHeader(ctx, next) {
const simValidator = new Validate();

simulator.use(async (ctx, next) => {
ctx.state.logger.log('Validating request');
try {
ctx.state.logger.push({ ctx_request: ctx.request }).log('validating request');
ctx.state.path = simValidator.validateRequest(ctx, ctx.state.logger);
ctx.state.logger.log('Request passed validation');
ctx.state.model = model;
if (ctx.path == '/' || ctx.path == '/health') {
ctx.state.logger.isDebugEnabled && ctx.state.logger.debug({'msg': 'Validating Request', request: ctx.request});
ctx.state.path = simValidator.validateRequest(ctx, ctx.state.logger);
ctx.state.logger.isDebugEnabled && ctx.state.logger.debug({'msg': 'Request passed validation', request: ctx.request});
ctx.state.model = model;
} else {
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Validating Request', request: ctx.request});
ctx.state.path = simValidator.validateRequest(ctx, ctx.state.logger);
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request passed validation', request: ctx.request});
ctx.state.model = model;
}
await next();
} catch (err) {
ctx.state.logger.push({ err }).log('Request failed validation.');
} catch (error) {
ctx.state.logger.isErrorEnabled && ctx.state.logger.error({'msg': 'Request passed validation', error});
ctx.response.status = 400;
ctx.response.body = {
message: err.message,
message: error.message,
statusCode: 400,
};
}
Expand All @@ -204,16 +247,16 @@ async function rewriteContentTypeHeader(ctx, next) {
const reportValidator = new Validate();

report.use(async (ctx, next) => {
ctx.state.logger.log('Validating request');
try {
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Validating Request', request: ctx.request});
ctx.state.path = reportValidator.validateRequest(ctx, ctx.state.logger);
ctx.state.logger.log('Request passed validation');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request passed validation', request: ctx.request});
await next();
} catch (err) {
ctx.state.logger.push({ err }).log('Request failed validation.');
} catch (error) {
ctx.state.logger.isErrorEnabled && ctx.state.logger.error({'msg': 'Request passed validation', error});
ctx.response.status = 400;
ctx.response.body = {
message: err.message,
message: error.message,
statusCode: 400,
};
}
Expand All @@ -222,17 +265,17 @@ async function rewriteContentTypeHeader(ctx, next) {
const testApiValidator = new Validate();

testApi.use(async (ctx, next) => {
ctx.state.logger.log('Validating request');
try {
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Validating Request', request: ctx.request});
ctx.state.path = testApiValidator.validateRequest(ctx, ctx.state.logger);
ctx.state.logger.log('Request passed validation');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info({'msg': 'Request passed validation', request: ctx.request});
ctx.state.model = model;
await next();
} catch (err) {
ctx.state.logger.push({ err }).log('Request failed validation.');
} catch (error) {
ctx.state.logger.isErrorEnabled && ctx.state.logger.error({'msg': 'Request passed validation', error});
ctx.response.status = 400;
ctx.response.body = {
message: err.message,
message: error.message,
statusCode: 400,
};
}
Expand All @@ -245,8 +288,11 @@ async function rewriteContentTypeHeader(ctx, next) {
body: ctx.request.body,
method: ctx.request.method,
};

ctx.state.logger.log(`Rules engine evaluating request against facts: ${util.inspect(facts)}`);
if (ctx.path == '/' || ctx.path == '/health') {
ctx.state.logger.isDebugEnabled && ctx.state.logger.debug(`Rules engine evaluating request against facts: ${util.inspect(facts)}`);
} else {
ctx.state.logger.isInfoEnabled && ctx.state.logger.info(`Rules engine evaluating request against facts: ${util.inspect(facts)}`);
}

const res = await rulesEngine.evaluate(facts);
if (res && res.length > 0) {
Expand All @@ -258,7 +304,7 @@ async function rewriteContentTypeHeader(ctx, next) {

if (evt.noResponse) {
// simulating no response
ctx.state.logger.log('Rule engine is triggering a no response scenario');
ctx.state.logger.isInfoEnabled && ctx.state.logger.info('Rule engine is triggering a no response scenario');
ctx.res.end();
return;
}
Expand Down Expand Up @@ -290,7 +336,7 @@ async function rewriteContentTypeHeader(ctx, next) {
}

const { body, statusCode } = res[0];
ctx.state.logger.log(`Rules engine returned a response for request: ${util.inspect(res)}.`);
ctx.state.logger.isInfoEnabled && ctx.state.logger.info(`Rules engine returned a response for request: ${util.inspect(res)}.`);
ctx.response.body = body;
ctx.response.status = statusCode;
return;
Expand Down Expand Up @@ -335,11 +381,11 @@ async function rewriteContentTypeHeader(ctx, next) {
} else {
simServer = simulator.listen(simulatorPort);
}
simLogger.log(`Serving simulator on port ${simulatorPort}`);
simLogger.isInfoEnabled && simLogger.info(`Serving simulator on port ${simulatorPort}`);
const reportServer = report.listen(reportPort);
reportLogger.log(`Serving report API on port ${reportPort}`);
reportLogger.isInfoEnabled && reportLogger.info(`Serving report API on port ${reportPort}`);
const testApiServer = testApi.listen(testApiPort);
testApiLogger.log(`Serving test API on port ${testApiPort}`);
testApiLogger.isInfoEnabled && testApiLogger.info(`Serving test API on port ${testApiPort}`);

// Gracefully handle shutdown. This should drain the servers.
process.on('SIGTERM', () => {
Expand Down
Loading

0 comments on commit 8a1573e

Please sign in to comment.