From 3beb57f7f6e999f953c7ac0caa3a70f4a9f78945 Mon Sep 17 00:00:00 2001 From: "Juan Picado @jotadeveloper" Date: Sat, 20 Jul 2019 18:05:51 +0200 Subject: [PATCH] test: add unit test for parser logger strings --- src/api/middleware.ts | 10 ++- src/lib/config-path.ts | 2 +- src/lib/logger.ts | 55 ++---------- src/lib/logger/index.ts | 0 src/lib/logger/parser.ts | 38 ++++++++ src/lib/utils.ts | 12 +++ test/unit/modules/api/api.spec.ts | 4 +- test/unit/modules/logger/parser.spec.ts | 115 ++++++++++++++++++++++++ tsconfig.json | 3 +- 9 files changed, 184 insertions(+), 55 deletions(-) create mode 100644 src/lib/logger/index.ts create mode 100644 src/lib/logger/parser.ts create mode 100644 test/unit/modules/logger/parser.spec.ts diff --git a/src/api/middleware.ts b/src/api/middleware.ts index 0e41dba3e..ee4959bac 100644 --- a/src/api/middleware.ts +++ b/src/api/middleware.ts @@ -175,6 +175,10 @@ export function final(body: FinalBody, req: $RequestExtend, res: $ResponseExtend res.send(body); } +export const LOG_STATUS_MESSAGE = "@{status}, user: @{user}(@{remoteIP}), req: '@{request.method} @{request.url}'"; +export const LOG_VERDACCIO_ERROR = `${LOG_STATUS_MESSAGE}, error: @{!error}`; +export const LOG_VERDACCIO_BYTES = `${LOG_STATUS_MESSAGE}, bytes: @{bytes.in}/@{bytes.out}`; + export function log(req: $RequestExtend, res: $ResponseExtend, next: $NextFunctionVer): void { // logger req.log = logger.child({ sub: 'in' }); @@ -221,11 +225,11 @@ export function log(req: $RequestExtend, res: $ResponseExtend, next: $NextFuncti const forwardedFor = req.headers['x-forwarded-for']; const remoteAddress = req.connection.remoteAddress; const remoteIP = forwardedFor ? `${forwardedFor} via ${remoteAddress}` : remoteAddress; - let message = "@{status}, user: @{user}(@{remoteIP}), req: '@{request.method} @{request.url}'"; + let message; if (res._verdaccio_error) { - message += ', error: @{!error}'; + message = LOG_VERDACCIO_ERROR; } else { - message += ', bytes: @{bytes.in}/@{bytes.out}'; + message = LOG_VERDACCIO_BYTES; } req.url = req.originalUrl; diff --git a/src/lib/config-path.ts b/src/lib/config-path.ts index b055713ea..dae4c2519 100644 --- a/src/lib/config-path.ts +++ b/src/lib/config-path.ts @@ -68,7 +68,7 @@ function updateStorageLinks(configLocation, defaultConfig) { // $XDG_DATA_HOME defines the base directory relative to which user specific data files should be stored, // If $XDG_DATA_HOME is either not set or empty, a default equal to $HOME/.local/share should be used. // $FlowFixMe - let dataDir = process.env.XDG_DATA_HOME || Path.join(process.env.HOME, '.local', 'share'); + let dataDir = process.env.XDG_DATA_HOME || Path.join(process.env.HOME as string, '.local', 'share'); if (folderExists(dataDir)) { dataDir = Path.resolve(Path.join(dataDir, pkgJSON.name, 'storage')); return defaultConfig.replace(/^storage: .\/storage$/m, `storage: ${dataDir}`); diff --git a/src/lib/logger.ts b/src/lib/logger.ts index 5e752ed88..17ee1bf17 100644 --- a/src/lib/logger.ts +++ b/src/lib/logger.ts @@ -1,6 +1,8 @@ /* eslint-disable */ -import { isObject } from './utils'; +import { isObject, pad } from './utils'; + +import { fillInMsgTemplate } from './logger/parser'; const cluster = require('cluster'); const Logger = require('bunyan'); @@ -177,51 +179,6 @@ for (const l in levels) { } } -/** - * Apply whitespaces based on the length - * @param {*} str the log message - * @return {String} - */ -function pad(str) { - if (str.length < max) { - return str + ' '.repeat(max - str.length); - } - return str; -} - -function fillInMsgTemplate(msg, obj, colors) { - return msg.replace(/@{(!?[$A-Za-z_][$0-9A-Za-z\._]*)}/g, (_, name) => { - let str = obj; - let is_error; - if (name[0] === '!') { - name = name.substr(1); - is_error = true; - } - - const _ref = name.split('.'); - for (let _i = 0; _i < _ref.length; _i++) { - const id = _ref[_i]; - if (isObject(str) || Array.isArray(str)) { - str = str[id]; - } else { - str = undefined; - } - } - - if (typeof str === 'string') { - if (!colors || str.includes('\n')) { - return str; - } else if (is_error) { - return red(str); - } else { - return green(str); - } - } else { - return require('util').inspect(str, null, null, colors); - } - }); -} - /** * Apply colors to a string based on level parameters. * @param {*} type @@ -230,7 +187,7 @@ function fillInMsgTemplate(msg, obj, colors) { * @param {*} colors * @return {String} */ -function print(type, msg, obj, colors) { + function print(type, msg, obj, colors) { if (typeof type === 'number') { type = calculateLevel(type); } @@ -253,9 +210,9 @@ function print(type, msg, obj, colors) { const sub = subsystems[colors ? 0 : 1][obj.sub] || subsystems[+!colors].default; if (colors) { - return ` ${levels[type](pad(type))}${white(`${sub} ${finalMessage}`)}`; + return ` ${levels[type](pad(type, max))}${white(`${sub} ${finalMessage}`)}`; } else { - return ` ${pad(type)}${sub} ${finalMessage}`; + return ` ${pad(type, max)}${sub} ${finalMessage}`; } } diff --git a/src/lib/logger/index.ts b/src/lib/logger/index.ts new file mode 100644 index 000000000..e69de29bb diff --git a/src/lib/logger/parser.ts b/src/lib/logger/parser.ts new file mode 100644 index 000000000..373c2bf3c --- /dev/null +++ b/src/lib/logger/parser.ts @@ -0,0 +1,38 @@ +import { inspect } from 'util'; +import { isObject } from '../utils'; +import { red, green } from 'kleur'; + +export function fillInMsgTemplate(msg, obj: unknown, colors): string { + return msg.replace(/@{(!?[$A-Za-z_][$0-9A-Za-z\._]*)}/g, (_, name): string => { + + let str = obj; + let is_error; + if (name[0] === '!') { + name = name.substr(1); + is_error = true; + } + + const _ref = name.split('.'); + for (let _i = 0; _i < _ref.length; _i++) { + const id = _ref[_i]; + if (isObject(str)) { + // @ts-ignore + str = str[id]; + } else { + str = undefined; + } + } + + if (typeof str === 'string') { + if (!colors || (str as string).includes('\n')) { + return str; + } else if (is_error) { + return red(str); + } else { + return green(str); + } + } else { + return inspect(str, undefined, null, colors); + } + }); +} diff --git a/src/lib/utils.ts b/src/lib/utils.ts index 1bc0ff545..e1d86be77 100644 --- a/src/lib/utils.ts +++ b/src/lib/utils.ts @@ -572,3 +572,15 @@ export function formatAuthor(author: AuthorFormat): any { export function isHTTPProtocol(uri: string): boolean { return /^(https?:)?\/\//.test(uri); } + +/** + * Apply whitespaces based on the length + * @param {*} str the log message + * @return {String} + */ +export function pad(str, max): string { + if (str.length < max) { + return str + ' '.repeat(max - str.length); + } + return str; +} diff --git a/test/unit/modules/api/api.spec.ts b/test/unit/modules/api/api.spec.ts index f6a464554..d025a4bb7 100644 --- a/test/unit/modules/api/api.spec.ts +++ b/test/unit/modules/api/api.spec.ts @@ -14,7 +14,9 @@ import {DOMAIN_SERVERS} from '../../../functional/config.functional'; import {buildToken} from '../../../../src/lib/utils'; import {getNewToken} from '../../__helper/api'; -require('../../../../src/lib/logger').setup([]); +require('../../../../src/lib/logger').setup([ + { type: 'stdout', format: 'pretty', level: 'info' } +]); const credentials = { name: 'jota', password: 'secretPass' }; const putPackage = (app, name, publishMetadata) => { diff --git a/test/unit/modules/logger/parser.spec.ts b/test/unit/modules/logger/parser.spec.ts new file mode 100644 index 000000000..cc0118cce --- /dev/null +++ b/test/unit/modules/logger/parser.spec.ts @@ -0,0 +1,115 @@ +import { fillInMsgTemplate } from "../../../../src/lib/logger/parser"; +import {LOG_VERDACCIO_ERROR, LOG_VERDACCIO_BYTES} from "../../../../src/api/middleware"; +import { HTTP_STATUS } from "@verdaccio/commons-api"; + +// the following mocks avoid use colors, thus the strings can be matched + +jest.mock('kleur', () => { + // we emulate colors with this pattern color[msg] + return { + green: r => `g[${r}]`, + red: r => `r[${r}]` + } +}); + +jest.mock('util', () => { + // we need to override only one method, but still we need others + const originalModule = jest.requireActual('util'); + return { + ...originalModule, + inspect: r => r, + } +}); + + +describe('Logger Parser', () => { + describe('basic messages', () => { + test('number object property', () => { + expect(fillInMsgTemplate('foo:@{foo}', {foo: 1}, false)).toEqual('foo:1'); + }); + + test('string object property', () => { + expect(fillInMsgTemplate('foo:@{foo}', {foo: 'bar'}, false)).toEqual('foo:bar'); + }); + + test('empty message no object property', () => { + expect(fillInMsgTemplate('foo', undefined, false)).toEqual('foo'); + }); + + test('string no object property', () => { + expect(fillInMsgTemplate('foo', null, false)).toEqual('foo'); + }); + + test('string no object property with break line ', () => { + expect(fillInMsgTemplate('foo \n bar', null, false)).toEqual('foo \n bar'); + }); + + test('string no object property with colors', () => { + expect(fillInMsgTemplate('foo', null, true)).toEqual('foo'); + }); + + test('string object property with colors', () => { + expect(fillInMsgTemplate('foo:@{foo}', {foo: 'bar'}, true)).toEqual(`foo:${'g[bar]'}`); + }); + }) + + describe('middleware log messages', () => { + describe('test errors log', () => { + const middlewareObject = { name: 'verdaccio', + request: { + method: 'POST', + url: '/-/npm/v1/user' + }, + user: 'userTest2001', + remoteIP: '::ffff:127.0.0.1', + status: HTTP_STATUS.UNAUTHORIZED, + error: 'some error', + msg: '@{status}, user: @{user}(@{remoteIP}), req: \'@{request.method} @{request.url}\', error: @{!error}' + }; + + test('should display error log', () => { + const expectedErrorMessage = `401, user: userTest2001(::ffff:127.0.0.1), req: 'POST /-/npm/v1/user', error: some error`; + expect(fillInMsgTemplate(LOG_VERDACCIO_ERROR, middlewareObject, false)) + .toEqual(expectedErrorMessage); + }); + + test('should display error log with colors', () => { + const expectedErrorMessage = `401, user: g[userTest2001](g[::ffff:127.0.0.1]), req: 'g[POST] g[/-/npm/v1/user]', error: r[some error]`; + expect(fillInMsgTemplate(LOG_VERDACCIO_ERROR, middlewareObject, true)) + .toEqual(expectedErrorMessage); + }); + }); + + describe('test bytes log', () => { + const middlewareObject = { name: 'verdaccio', + hostname: 'macbook-touch', + pid: 85621, + sub: 'in', + level: 35, + request: { + method: 'PUT', + url: '/-/user/org.couchdb.user:userTest2002' + }, + user: 'userTest2002', + remoteIP: '::ffff:127.0.0.1', + status: 201, + error: undefined, + bytes: { in: 50, out: 405 }, + msg: + '@{status}, user: @{user}(@{remoteIP}), req: \'@{request.method} @{request.url}\', bytes: @{bytes.in}/@{bytes.out}', + time: '2019-07-20T11:31:49.939Z', + v: 0 + } + + test('should display log with bytes', () => { + expect(fillInMsgTemplate(LOG_VERDACCIO_BYTES, middlewareObject, false)) + .toEqual(`201, user: userTest2002(::ffff:127.0.0.1), req: 'PUT /-/user/org.couchdb.user:userTest2002', bytes: 50/405`); + }); + + test('should display log with bytes with colors', () => { + expect(fillInMsgTemplate(LOG_VERDACCIO_BYTES, middlewareObject, true)) + .toEqual(`201, user: g[userTest2002](g[::ffff:127.0.0.1]), req: 'g[PUT] g[/-/user/org.couchdb.user:userTest2002]', bytes: 50/405`); + }); + }); + }); +}); diff --git a/tsconfig.json b/tsconfig.json index d7b62672e..90751aabd 100644 --- a/tsconfig.json +++ b/tsconfig.json @@ -19,7 +19,8 @@ "node_modules" ], "include": [ - "src/*.ts", + "src/**/*.ts", + "test/**/.ts", "types/*.d.ts" ] }