Skip to content

Commit

Permalink
Feat/logger and api logger (#69)
Browse files Browse the repository at this point in the history
* chore: install dependencies needed for logger component

This commit installs the necessary dependencies for the logger
component. The reason we need a separate logger, which logs to
CloudWatch directly, is because the EC2 instance that our server
is running on might batches log statements before sending them to
CloudWatch. Logs might fail to get sent if the EC2 cloudwatch daemon
is corrupted or fails in some way. This external logger will send
logs instantly to CloudWatch so we have a fallback source of logs.

We chose to use the Winston logger as we have had success using it
for the homer project. this commit also installs the aws sdk as we
need to retrieve the EC2 instance id to log to the correct
cloudwatch log group.

* feat: add singleton CloudWatchLogger class

This commit adds a CloudWatchLogger class which uses the singleton
pattern. Since a logger does not hold any state, it makes sense to
use the singleton pattern.

This logger attempts to connect to and log directly to cloudwatch
if in a production environment (NODE_ENV = prod or staging) and
logs directly to console if in dev mode. In other words, in a prod
environment we log both directly to cloudwatch and to console, so we
have two sets of logs as a fallback mechanism. In particular, our
cloudwatch only logs provide a clean application log which make it
easier to debug our own operations.

* chore: remove try-catch statements

This commit removes try-catch statements that we were supposed to
remove in PR #63 but which we forgot to do so. These blocks are
no longer needed since we have a central error handler which deals
with errors.

* feat: replace existing usage of console.log

This commit replaces existing usage of console.log with our
new logger class' `logger.info` method

* feat: retrieve user id for logging purposes

This commit retrieves a user's GitHub id during the login
authentication stage for auditing purposes so that we can
log user actions when they perform actions on the CMS.

* feat: add userId attribute to request object in auth middleware

This commit extracts the newly added user_id attribute from the JWT
during the request authentication stage and attaches it to the request
object. This allows us to identify user logs by their GitHub user id
instead of an unidentifiable access token string.

* fix: assign verifyJwt auth function to logout endpoint

Previously, we erroneously assigned the logout endpoint the `noVerify`
auth function. However, the logout endpoint should not be accesible
to users who have not logged in, therefore it should be a protected
endpoint.

* feat: add api-logging middleware

This commit adds an api logger middleware which logs all api requests
that have been submitted to the server for auditing purposes. Note that
this middleware is added AFTER the auth middleware instead of before -
that's because we're reliant on the auth middleware to add the user id
to the request object which will allow our api logs to be identifiable.

* fix: remove logging of request body

This commit modifies the API logger so that we log the request body.
The request body usually contains encrypted post content, and the relevant
file sha, which isn't important to us when we're sifting the logs.
Furthermore, we can identify the files being changes simply by looking
at the request path and date-time of the request - from these, we would
be able to identify the file being changed and also identify the file
version from the date-time of teh request.
that useful to us when we

* fix: unprotect logout endpoint

Currently, the logout endpoint is protected by the `verifyJwt` auth
function. However, this prevents auto-logout functionality for when
a user's token expires, leaving them stuck in the UI with a useless
JWT which is incapable of making successful API calls.

This commit reverts the endpoint to be unprotected to fix this problem.

Co-authored-by: Jie Hao Kwa <[email protected]>
  • Loading branch information
kwajiehao and Jie Hao Kwa authored Nov 20, 2020
1 parent d7f8b27 commit 006f0fd
Show file tree
Hide file tree
Showing 14 changed files with 1,094 additions and 144 deletions.
9 changes: 6 additions & 3 deletions bin/www
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,9 @@ const app = require('../server');
const debug = require('debug')('isomercms:server');
const http = require('http');

// Import logger
const logger = require('../logger/logger');

/**
* Get port from environment and store in Express.
*/
Expand Down Expand Up @@ -65,11 +68,11 @@ function onError(error) {
// handle specific listen errors with friendly messages
switch (error.code) {
case 'EACCES':
console.error(bind + ' requires elevated privileges');
logger.error(bind + ' requires elevated privileges');
process.exit(1);
break;
case 'EADDRINUSE':
console.error(bind + ' is already in use');
logger.error(bind + ' is already in use');
process.exit(1);
break;
default:
Expand All @@ -87,5 +90,5 @@ function onListening() {
? 'pipe ' + addr
: 'port ' + addr.port;
debug('Listening on ' + bind);
console.log(`isomerCMS app listening on port ${port}`)
logger.info(`isomerCMS app listening on port ${port}`)
}
31 changes: 15 additions & 16 deletions classes/Config.js
Original file line number Diff line number Diff line change
@@ -1,6 +1,9 @@
const axios = require('axios');
const validateStatus = require('../utils/axios-utils')

// Import logger
const logger = require('../logger/logger');

// Import error
const { NotFoundError } = require('../errors/NotFoundError')

Expand Down Expand Up @@ -42,25 +45,21 @@ class Config {
}

async update(newContent, sha) {
try {
const endpoint = `https://api.github.com/repos/${GITHUB_ORG_NAME}/${this.siteName}/contents/_config.yml`
const endpoint = `https://api.github.com/repos/${GITHUB_ORG_NAME}/${this.siteName}/contents/_config.yml`

const params = {
"message": 'Edit config',
"content": newContent,
"branch": BRANCH_REF,
"sha": sha
}
const params = {
"message": 'Edit config',
"content": newContent,
"branch": BRANCH_REF,
"sha": sha
}

await axios.put(endpoint, params, {
headers: {
Authorization: `token ${this.accessToken}`,
"Content-Type": "application/json"
}
})
} catch (err) {
console.log(err)
}
headers: {
Authorization: `token ${this.accessToken}`,
"Content-Type": "application/json"
}
})
}
}

Expand Down
122 changes: 57 additions & 65 deletions classes/Settings.js
Original file line number Diff line number Diff line change
Expand Up @@ -16,75 +16,67 @@ class Settings {
}

async get() {
try {
// retrieve _config.yml and footer.yml
const configResp = new Config(this.accessToken, this.siteName)

const IsomerDataFile = new File(this.accessToken, this.siteName)
const dataType = new DataType()
IsomerDataFile.setFileType(dataType)

const fileRetrievalArr = [configResp.read(), IsomerDataFile.read(FOOTER_PATH)]

const fileContentsArr = await Bluebird.map(fileRetrievalArr, async (fileOp) => {
const { content, sha } = await fileOp
return { content, sha}
})

// convert data to object form
const configContent = fileContentsArr[0].content
const footerContent = fileContentsArr[1].content

const configReadableContent = yaml.safeLoad(Base64.decode(configContent));
const footerReadableContent = yaml.safeLoad(Base64.decode(footerContent));

// retrieve only the relevant config and index fields
const configFieldsRequired = {
url: configReadableContent.url,
title: configReadableContent.title,
favicon: configReadableContent.favicon,
resources_name: configReadableContent.resources_name,
colors: configReadableContent.colors,
}

// retrieve footer sha since we are sending the footer object wholesale
const footerSha = fileContentsArr[1].sha

return ({ configFieldsRequired, footerContent: footerReadableContent, footerSha })
} catch (err) {
console.log(err)
// retrieve _config.yml and footer.yml
const configResp = new Config(this.accessToken, this.siteName)

const IsomerDataFile = new File(this.accessToken, this.siteName)
const dataType = new DataType()
IsomerDataFile.setFileType(dataType)

const fileRetrievalArr = [configResp.read(), IsomerDataFile.read(FOOTER_PATH)]

const fileContentsArr = await Bluebird.map(fileRetrievalArr, async (fileOp) => {
const { content, sha } = await fileOp
return { content, sha}
})

// convert data to object form
const configContent = fileContentsArr[0].content
const footerContent = fileContentsArr[1].content

const configReadableContent = yaml.safeLoad(Base64.decode(configContent));
const footerReadableContent = yaml.safeLoad(Base64.decode(footerContent));

// retrieve only the relevant config and index fields
const configFieldsRequired = {
url: configReadableContent.url,
title: configReadableContent.title,
favicon: configReadableContent.favicon,
resources_name: configReadableContent.resources_name,
colors: configReadableContent.colors,
}

// retrieve footer sha since we are sending the footer object wholesale
const footerSha = fileContentsArr[1].sha

return ({ configFieldsRequired, footerContent: footerReadableContent, footerSha })
}

async post(payload) {
try {
// setup
const configResp = new Config(this.accessToken, this.siteName)
const config = await configResp.read()
const IsomerDataFile = new File(this.accessToken, this.siteName)
const dataType = new DataType()
IsomerDataFile.setFileType(dataType)

// extract data
const {
footerSettings,
configSettings,
footerSha,
} = payload

// update config object
const configContent = yaml.safeLoad(Base64.decode(config.content));
Object.keys(configSettings).forEach((setting) => (configContent[setting] = configSettings[setting]));

// update files
const newConfigContent = Base64.encode(yaml.safeDump(configContent))
const newFooterContent = Base64.encode(yaml.safeDump(footerSettings))
await configResp.update(newConfigContent, config.sha)
await IsomerDataFile.update(FOOTER_PATH, newFooterContent, footerSha)
return
} catch (err) {
console.log(err)
}
// setup
const configResp = new Config(this.accessToken, this.siteName)
const config = await configResp.read()
const IsomerDataFile = new File(this.accessToken, this.siteName)
const dataType = new DataType()
IsomerDataFile.setFileType(dataType)

// extract data
const {
footerSettings,
configSettings,
footerSha,
} = payload

// update config object
const configContent = yaml.safeLoad(Base64.decode(config.content));
Object.keys(configSettings).forEach((setting) => (configContent[setting] = configSettings[setting]));

// update files
const newConfigContent = Base64.encode(yaml.safeDump(configContent))
const newFooterContent = Base64.encode(yaml.safeDump(footerSettings))
await configResp.update(newConfigContent, config.sha)
await IsomerDataFile.update(FOOTER_PATH, newFooterContent, footerSha)
return
}
}

Expand Down
101 changes: 101 additions & 0 deletions logger/logger.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,101 @@
// Imports
const Bluebird = require('bluebird')
const moment = require('moment-timezone')

// Env vars
const { NODE_ENV } = process.env

// AWS
const AWS = require('aws-sdk')

const AWS_REGION_NAME = 'ap-southeast-1'
AWS.config.update({ region: AWS_REGION_NAME })
const awsMetadata = new AWS.MetadataService()
const metadataRequest = Bluebird.promisify(awsMetadata.request.bind(awsMetadata))

// Logging tools
const winston = require('winston')
const WinstonCloudWatch = require('winston-cloudwatch')

// Constants
const LOG_GROUP_NAME = `${process.env.AWS_BACKEND_EB_ENV_NAME}/nodejs.log`
const IS_PROD_ENV = NODE_ENV !== 'LOCAL_DEV' && NODE_ENV !== 'DEV'

// Retrieve EC2 instance since that is the cloudwatch log stream name
async function getEc2InstanceId () {
let id
try {
id = await metadataRequest('/latest/meta-data/instance-id').timeout(1000)
} catch (error) {
// eslint-disable-next-line no-console
console.log(timestampGenerator(), 'Error getting ec2 instance id. This script is probably not running on ec2')
throw error
}
return id
}

function timestampGenerator () {
return moment().tz('Asia/Singapore')
.format('YYYY-MM-DD HH:mm:ss')
}
class CloudWatchLogger {
constructor () {
this._logger = winston.createLogger()
}

async init () {
if (IS_PROD_ENV) {
try {
// attempt to log directly to cloudwatch
const logGroupName = LOG_GROUP_NAME
const logStreamName = await getEc2InstanceId()
const awsRegion = AWS_REGION_NAME

const cloudwatchConfig = {
logGroupName,
logStreamName,
awsRegion,
stderrLevels: ['error'],
format: winston.format.simple(),
handleExceptions: true,
}

this._logger.add(new WinstonCloudWatch(cloudwatchConfig))
} catch (err) {
console.error(`${timestampGenerator()} ${err.message}`)
console.error(`${timestampGenerator()} Failed to initiate CloudWatch logger`)
}
}
}

// this method is used to log non-error messages, replacing console.log
async info (logMessage) {
// eslint-disable-next-line no-console
console.log(`${timestampGenerator()} ${logMessage}`)

if (IS_PROD_ENV) {
try {
await this._logger.info(`${timestampGenerator()} ${logMessage}`)
} catch (err) {
console.error(`${timestampGenerator()} ${err.message}`)
}
}
}

// this method is used to log error messages and write to stderr, replacing console.error
async error (errMessage) {
console.error(`${timestampGenerator()} ${errMessage}`)

if (IS_PROD_ENV) {
try {
await this._logger.error(`${timestampGenerator()} ${errMessage}`)
} catch (err) {
console.error(`${timestampGenerator()} ${err.message}`)
}
}
}
}

const logger = new CloudWatchLogger()

module.exports = logger
29 changes: 29 additions & 0 deletions middleware/apiLogger.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
// Imports
const express = require('express')

// Logger
const logger = require('../logger/Logger')

const apiLogger = express.Router()

apiLogger.use((req, res, next) => {
function isObjEmpty (obj) {
return Object.keys(obj).length === 0
}

// Get IP address
const ipAddress = req.headers['x-forwarded-for']

// Get user GitHub id
let userId
if (req.userId) userId = req.userId

let logMessage = `User ${userId} from IP address ${ipAddress ? `(IP: ${ipAddress})` : undefined } called ${req.method} on ${req.path}`
if (!isObjEmpty(req.query)) {
logMessage += ` with query ${JSON.stringify(req.query)}`
}
logger.info(logMessage)
return next()
})

module.exports = { apiLogger }
8 changes: 6 additions & 2 deletions middleware/auth.js
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,9 @@
const express = require('express')
const jwtUtils = require('../utils/jwt-utils')

// Import logger
const logger = require('../logger/logger')

// Import errors
const { AuthError } = require('../errors/AuthError')
const { verify } = require('jsonwebtoken')
Expand All @@ -17,10 +20,11 @@ function noVerify (req, res, next) {
const verifyJwt = (req, res, next) => {
try {
const { isomercms } = req.cookies
const { access_token } = jwtUtils.verifyToken(isomercms)
const { access_token, user_id } = jwtUtils.verifyToken(isomercms)
req.accessToken = access_token
req.userId = user_id
} catch (err) {
console.error('Authentication error')
logger.error('Authentication error')
if (err.name === 'TokenExpiredError') {
throw new AuthError('JWT token has expired')
}
Expand Down
6 changes: 5 additions & 1 deletion middleware/errorHandler.js
Original file line number Diff line number Diff line change
@@ -1,7 +1,11 @@
// Import dependencies
const { serializeError } = require('serialize-error')

// Import logger
const logger = require('../logger/logger');

function errorHandler (err, req, res, next) {
console.log(`${new Date()}: ${JSON.stringify(serializeError(err))}`)
logger.info(`${new Date()}: ${JSON.stringify(serializeError(err))}`)

// set locals, only providing error in development
res.locals.message = err.message;
Expand Down
Loading

0 comments on commit 006f0fd

Please sign in to comment.