/*! * Copyright (c) 2020 Ville de Montreal. All rights reserved. * Licensed under the MIT license. * See LICENSE file in the project root for full license information. */ import { Stopwatch, ILogger, extractMessageFromError, TypedProperty, } from '@villedemontreal/auth-core'; import { Request, Response } from 'request'; import { makeRequestPlugin } from './makeRequestPlugin'; import { getRequestInfo } from './requestUtils'; const watchProperty = new TypedProperty(Symbol('watch')); /** * plugin that will log a message before and after the execution of request, * and provide additional information such as status code, elapsed time, error... * @param logger the logger * @example * const config: request.CoreOptions = { * url: 'http://localhost:4004/secured/profile' * }; * requestLogger(new ConsoleLogger()).bind(config); * const response = await request(config); * @example * const correlator = new HttpRequestCorrelator(); * const config: request.CoreOptions = { * url: 'http://localhost:4004/secured/profile' * }; * requestCorrelator(correlator).bind(config); * requestLogger(new ConsoleLogger(() => correlator.getId())).bind(config); * const response = await request(config); * @example * const defaultConfig: request.CoreOptions = {}; * requestLogger(new ConsoleLogger()).bind(defaultConfig); * const config: request.CoreOptions = { * ...defaultConfig, * baseUrl: 'http://localhost:4004', * }; * const response = await request.get('/secured/profile', config); * @example * const config: request.CoreOptions = {}; * authenticator(session, authenticatorConfig).bind(config); * requestLogger(session.logger).bind(config); * const response = await request.get('http://localhost:4004/secured/profile', config); */ export function requestLogger(logger: ILogger) { return makeRequestPlugin({ //-------------------------------------------------------------------- onStart(req: Request): Promise { req.on('request', () => { watchProperty.set(req, Stopwatch.startNew()); const { method, url } = getRequestInfo(req); logger.debug({ method, url }, `Start of ${method} ${url}`); }); return Promise.resolve(); }, //-------------------------------------------------------------------- onComplete(req: Request, res: Response): Promise { const { method, url } = getRequestInfo(req); const watch = watchProperty.getOrSet(req, Stopwatch.startNew); const elapsedTimeInMS = watch.elapsedTimeInMS(); const { statusCode } = res; logger.debug( { method, url, elapsedTimeInMS, statusCode }, `End of ${method} ${url} => ${statusCode} in ${elapsedTimeInMS} ms`, ); return Promise.resolve(); }, //-------------------------------------------------------------------- onError(error: Error, req: Request, res?: Response): Promise { const { method, url } = getRequestInfo(req); const watch = watchProperty.getOrSet(req, Stopwatch.startNew); const elapsedTimeInMS = watch.elapsedTimeInMS(); const errorMessage = extractMessageFromError(error); logger.error( { method, url, elapsedTimeInMS, error }, `${method} ${url} failed in ${elapsedTimeInMS} ms: ${errorMessage}`, ); return Promise.resolve(); }, }); }