Skip to content

Commit

Permalink
Merge pull request #18 from onaio/update-logging
Browse files Browse the repository at this point in the history
Update logging
  • Loading branch information
machariamuguku authored Nov 10, 2021
2 parents 2e48d41 + fbb600e commit a73dcd6
Show file tree
Hide file tree
Showing 10 changed files with 292 additions and 214 deletions.
160 changes: 80 additions & 80 deletions package.json
Original file line number Diff line number Diff line change
@@ -1,83 +1,83 @@
{
"license": "Apache-2.0",
"scripts": {
"clean": "rimraf dist/*",
"tsc": "tsc",
"build": "npm-run-all clean tsc",
"dev:start": "npm-run-all build start",
"dev": "nodemon --watch src -e ts,ejs --exec npm run dev:start",
"start": "node dist",
"test": "jest",
"test:coverage": "jest --coverage --no-cache",
"lint": "tsc --noEmit && eslint src/**/*.{js,ts} --quiet"
},
"husky": {
"hooks": {
"pre-commit": "tsc --noEmit && lint-staged"
"license": "Apache-2.0",
"scripts": {
"clean": "rimraf dist/*",
"tsc": "tsc",
"build": "npm-run-all clean tsc",
"dev:start": "npm-run-all build start",
"dev": "nodemon --watch src -e ts,ejs --exec npm run dev:start",
"start": "node dist",
"test": "jest",
"test:coverage": "jest --coverage --no-cache",
"lint": "tsc --noEmit && eslint src/**/*.{js,ts} --quiet"
},
"husky": {
"hooks": {
"pre-commit": "tsc --noEmit && lint-staged"
}
},
"lint-staged": {
"*.{js,ts}": [
"eslint --fix"
],
"*.{json,md}": [
"prettier --write"
]
},
"dependencies": {
"@onaio/gatekeeper": "^0.1.1",
"compression": "^1.7.4",
"cookie-parser": "^1.4.4",
"dotenv": "^8.2.0",
"express": "^4.17.1",
"express-session": "^1.17.0",
"helmet": "^3.21.2",
"morgan": "^1.10.0",
"node-fetch": "^2.6.1",
"react": "^16.13.1",
"react-dom": "^16.13.1",
"react-redux": "^7.2.0",
"react-router": "^5.1.2",
"react-router-dom": "^5.1.2",
"redux": "^4.0.5",
"request": "^2.88.0",
"seamless-immutable": "^7.1.4",
"session-file-store": "^1.3.1",
"typescript": "^3.7.5",
"winston": "^3.3.3"
},
"devDependencies": {
"@types/compression": "^1.0.1",
"@types/cookie-parser": "^1.4.2",
"@types/express": "^4.17.2",
"@types/express-session": "^1.15.16",
"@types/helmet": "^0.0.45",
"@types/jest": "^25.1.3",
"@types/lodash": "^4.14.149",
"@types/morgan": "^1.9.2",
"@types/node": "^13.5.0",
"@types/node-fetch": "^2.5.8",
"@types/react": "^16.9.32",
"@types/react-redux": "7.1.7",
"@types/react-router": "^5.1.5",
"@types/request": "^2.48.4",
"@types/seamless-immutable": "^7.1.11",
"@types/session-file-store": "^1.2.1",
"@types/supertest": "^2.0.8",
"@typescript-eslint/eslint-plugin": "^2.27.0",
"@typescript-eslint/parser": "^2.27.0",
"coveralls": "^3.0.11",
"eslint": "^6.8.0",
"eslint-config-prettier": "^6.10.1",
"eslint-plugin-prettier": "^3.1.2",
"jest": "^25.1.0",
"mockdate": "^3.0.2",
"nock": "^12.0.1",
"nodemon": "^2.0.2",
"npm-run-all": "^4.1.5",
"prettier": "^2.0.4",
"rimraf": "^3.0.1",
"supertest": "^4.0.2",
"ts-jest": "^25.2.1"
}
},
"lint-staged": {
"*.{js,ts}": [
"eslint --fix"
],
"*.{json,md}": [
"prettier --write"
]
},
"dependencies": {
"@onaio/gatekeeper": "^0.1.1",
"compression": "^1.7.4",
"cookie-parser": "^1.4.4",
"dotenv": "^8.2.0",
"express": "^4.17.1",
"express-session": "^1.17.0",
"helmet": "^3.21.2",
"morgan": "^1.10.0",
"node-fetch": "^2.6.1",
"react": "^16.13.1",
"react-dom": "^16.13.1",
"react-redux": "^7.2.0",
"react-router": "^5.1.2",
"react-router-dom": "^5.1.2",
"redux": "^4.0.5",
"request": "^2.88.0",
"seamless-immutable": "^7.1.4",
"session-file-store": "^1.3.1",
"typescript": "^3.7.5",
"winston": "^3.3.3"
},
"devDependencies": {
"@types/compression": "^1.0.1",
"@types/cookie-parser": "^1.4.2",
"@types/express": "^4.17.2",
"@types/express-session": "^1.15.16",
"@types/helmet": "^0.0.45",
"@types/jest": "^25.1.3",
"@types/lodash": "^4.14.149",
"@types/morgan": "^1.9.2",
"@types/node": "^13.5.0",
"@types/node-fetch": "^2.5.8",
"@types/react": "^16.9.32",
"@types/react-redux": "7.1.7",
"@types/react-router": "^5.1.5",
"@types/request": "^2.48.4",
"@types/seamless-immutable": "^7.1.11",
"@types/session-file-store": "^1.2.1",
"@types/supertest": "^2.0.8",
"@typescript-eslint/eslint-plugin": "^2.27.0",
"@typescript-eslint/parser": "^2.27.0",
"coveralls": "^3.0.11",
"eslint": "^6.8.0",
"eslint-config-prettier": "^6.10.1",
"eslint-plugin-prettier": "^3.1.2",
"jest": "^25.1.0",
"mockdate": "^3.0.2",
"nock": "^12.0.1",
"nodemon": "^2.0.2",
"npm-run-all": "^4.1.5",
"prettier": "^2.0.4",
"rimraf": "^3.0.1",
"supertest": "^4.0.2",
"ts-jest": "^25.2.1"
}
}
73 changes: 44 additions & 29 deletions src/app/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,6 @@ import {
} from '../configs/envs';
import { SESSION_IS_EXPIRED, TOKEN_NOT_FOUND, TOKEN_REFRESH_FAILED } from '../constants';


type dictionary = { [key: string]: any };

const opensrpAuth = new ClientOAuth2({
Expand All @@ -60,8 +59,10 @@ app.use(helmet()); // protect against well known vulnerabilities
app.use(morgan('combined', { stream: winstonStream })); // send logs to winston

const FileStore = sessionFileStore(session);
const fileStoreOptions = {
const fileStoreOptions: sessionFileStore.Options = {
path: EXPRESS_SESSION_FILESTORE_PATH || './sessions',
// channel session-file-store warnings to winston
logFn: (message) => winstonLogger.info(message),
};

let nextPath: string | undefined;
Expand Down Expand Up @@ -129,14 +130,15 @@ const processUserInfo = (
res: express.Response,
authDetails: dictionary,
userDetails?: dictionary,
isRefresh?: boolean
isRefresh?: boolean,
) => {
let userInfo = userDetails
let userInfo = userDetails;
const date = new Date(Date.now());
const sessionExpiryTime = req.session?.preloadedState?.session_expires_at;
const sessionExpiresAt = isRefresh ? sessionExpiryTime
const sessionExpiresAt = isRefresh
? sessionExpiryTime
: new Date(date.setSeconds(date.getSeconds() + EXPRESS_MAXIMUM_SESSION_LIFE_TIME)).toISOString();
if(!userDetails) {
if (!userDetails) {
// get user details from session. will be needed when refreshing token
userInfo = req.session.preloadedState?.session?.extraData || {};
}
Expand All @@ -159,8 +161,8 @@ const processUserInfo = (
// you have to save the session manually for POST requests like this one
req.session.save(() => void 0);
// when refreshing token we only need the preloaded state
if(isRefresh) {
return preloadedState
if (isRefresh) {
return preloadedState;
}
if (nextPath) {
/** reset nextPath to undefined; its value once set should only be used
Expand All @@ -174,35 +176,40 @@ const processUserInfo = (
}
return res.redirect(EXPRESS_FRONTEND_OPENSRP_CALLBACK_URL);
}
}
};

const refreshToken = (req: express.Request, res: express.Response) => {
const refreshToken = (req: express.Request, res: express.Response, next: express.NextFunction) => {
// check if token refreshing is allowed
if(!EXPRESS_ALLOW_TOKEN_RENEWAL) {
return res.status(500).send({message: SESSION_IS_EXPIRED});
if (!EXPRESS_ALLOW_TOKEN_RENEWAL) {
winstonLogger.info(SESSION_IS_EXPIRED);
return res.status(500).send({ message: SESSION_IS_EXPIRED });
}
const accessToken = req.session.preloadedState?.session?.extraData?.oAuth2Data?.access_token;
const refreshToken = req.session.preloadedState?.session?.extraData?.oAuth2Data?.refresh_token;
const sessionExpiryTime = req.session?.preloadedState?.session_expires_at;
if(!accessToken || !refreshToken || !sessionExpiryTime) {
return res.status(500).send({message: TOKEN_NOT_FOUND});
if (!accessToken || !refreshToken || !sessionExpiryTime) {
winstonLogger.info(TOKEN_NOT_FOUND);
return res.status(500).send({ message: TOKEN_NOT_FOUND });
}
// check if session set maxmum life is exceeded
if(new Date(Date.now()) >= new Date(sessionExpiryTime)) {
return res.status(500).send({message: SESSION_IS_EXPIRED});
if (new Date(Date.now()) >= new Date(sessionExpiryTime)) {
winstonLogger.info(SESSION_IS_EXPIRED);
return res.status(500).send({ message: SESSION_IS_EXPIRED });
}
const provider = opensrpAuth;
// re-create an access token instance
const token = provider.createToken(accessToken, refreshToken)
return token.refresh()
.then(oauthRes => {
const token = provider.createToken(accessToken, refreshToken);
return token
.refresh()
.then((oauthRes) => {
const preloadedState = processUserInfo(req, res, oauthRes.data, undefined, true);
return res.json(preloadedState)
return res.json(preloadedState);
})
.catch((error: Error) => {
return res.status(500).send({message: error.message || TOKEN_REFRESH_FAILED});
next(error); // pass error to express
return res.status(500).send({ message: error.message || TOKEN_REFRESH_FAILED });
});
}
};

const oauthCallback = (req: express.Request, res: express.Response, next: express.NextFunction) => {
const provider = opensrpAuth;
Expand Down Expand Up @@ -231,13 +238,14 @@ const oauthCallback = (req: express.Request, res: express.Response, next: expres
);
})
.catch((e: Error) => {
next(e);
next(e); // pass error to express
});
};

const oauthState = (req: express.Request, res: express.Response) => {
// check if logged in
if (!req.session.preloadedState) {
winstonLogger.info(`Not authorized`);
return res.json({ error: 'Not authorized' });
}
// only return this when user has valid session
Expand All @@ -259,7 +267,7 @@ const loginRedirect = (req: express.Request, res: express.Response, _: express.N
};

const logout = async (req: express.Request, res: express.Response) => {
if(req.query.serverLogout) {
if (req.query.serverLogout) {
const accessToken = req.session.preloadedState?.session?.extraData?.oAuth2Data?.access_token;
const payload = {
headers: {
Expand All @@ -268,11 +276,11 @@ const logout = async (req: express.Request, res: express.Response) => {
authorization: `Bearer ${accessToken}`,
},
method: 'GET',
}
if(accessToken) {
};
if (accessToken) {
await fetch(EXPRESS_OPENSRP_LOGOUT_URL, payload);
}
const keycloakLogoutFullPath = `${EXPRESS_KEYCLOAK_LOGOUT_URL}?redirect_uri=${EXPRESS_SERVER_LOGOUT_URL}`
const keycloakLogoutFullPath = `${EXPRESS_KEYCLOAK_LOGOUT_URL}?redirect_uri=${EXPRESS_SERVER_LOGOUT_URL}`;
res.redirect(keycloakLogoutFullPath);
} else {
req.session.destroy(() => void 0);
Expand Down Expand Up @@ -302,9 +310,16 @@ router.use('*', renderer);
// tell the app to use the above rules
app.use(router);

app.use((err: HttpException, _: express.Request, res: express.Response, __: express.NextFunction) => {
export const errorHandler = (
err: HttpException,
_: express.Request,
res: express.Response,
__: express.NextFunction,
) => {
winstonLogger.error(`${err.statusCode || 500} - ${err.message}-${JSON.stringify(err.stack)}`);
handleError(err, res);
});
};

app.use(errorHandler);

export default app;
6 changes: 3 additions & 3 deletions src/app/tests/index.errors.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -53,9 +53,9 @@ describe('src/index.ts', () => {
.end((err: Error, res: request.Response) => {
panic(err, done);
expect(spyOnError.mock.calls).toEqual([
["Token not found"],
["cannot GET /oauth/callback/OpenSRP/?code=Boi4Wz&state=opensrp (500)"],
["Internal Server Error"]
['Token not found'],
['cannot GET /oauth/callback/OpenSRP/?code=Boi4Wz&state=opensrp (500)'],
['Internal Server Error'],
]);
expect(res.notFound).toBeFalsy();
expect(res.serverError).toBeTruthy();
Expand Down
12 changes: 7 additions & 5 deletions src/app/tests/index.logging.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -99,9 +99,11 @@ describe('src/index.ts', () => {
request(app)
.get('/oauth/state')
.end(() => {
expect(logsSpy).toHaveBeenCalledTimes(1);
// one by winston, other by morgan
expect(logsSpy).toHaveBeenCalledTimes(2);
expect(logsSpy).toHaveBeenCalledWith(`Not authorized`);
expect(logsSpy).toHaveBeenCalledWith(
/* eslint-disable-next-line no-useless-escape */
/* eslint-disable-next-line no-useless-escape */
`::ffff:127.0.0.1 - - [01/Jan/2020:00:00:00 +0000] \"GET /oauth/state HTTP/1.1\" 200 26 \"-\" \"node-superagent/3.8.3\"\n`,
);
done();
Expand All @@ -125,9 +127,9 @@ describe('src/index.ts', () => {
panic(err, done);
expect(res.notFound).toBeFalsy();
expect(errorSpy).toHaveBeenCalledTimes(1);
// We will only check part of the error
// because the other part points to directories and specific file numbers were the error occured.
// This will be unstable to test because any additional code changing
// We will only check part of the error
// because the other part points to directories and specific file numbers were the error occured.
// This will be unstable to test because any additional code changing
// the line were the error occures leads to failure of the test
expect((errorSpy.mock.calls[0][0] as any).split('at CodeFlow')[0]).toEqual(
/* eslint-disable-next-line no-useless-escape */
Expand Down
Loading

0 comments on commit a73dcd6

Please sign in to comment.