diff --git a/.github/workflows/release-canary.yml b/.github/workflows/release-canary.yml index 3fee1737c..30e4f9964 100644 --- a/.github/workflows/release-canary.yml +++ b/.github/workflows/release-canary.yml @@ -13,11 +13,11 @@ jobs: with: node_version: 13 - name: Install - run: yarn install --no-lockfile - - name: Lint - run: yarn lint + run: yarn - name: Clean run: yarn clean + - name: Lint + run: yarn lint - name: Build run: yarn build - name: Test diff --git a/.gitignore b/.gitignore index a453ccfdd..60b25c17b 100644 --- a/.gitignore +++ b/.gitignore @@ -1,4 +1,4 @@ -npm-debug.log +*.log* verdaccio-*.tgz .DS_Store build/ diff --git a/package.json b/package.json index e358638d7..79d964986 100644 --- a/package.json +++ b/package.json @@ -21,7 +21,6 @@ "@commitlint/config-conventional": "8.2.0", "@octokit/rest": "17.0.0", "@types/async": "3.0.3", - "@types/bunyan": "1.8.6", "@types/express": "4.17.1", "@types/http-errors": "1.6.3", "@types/jest": "24.0.25", @@ -55,7 +54,7 @@ "selfsigned": "1.10.7", "standard-version": "^7.0.1", "supertest": "^4.0.2", - "typescript": "^3.8.3", + "typescript": "beta", "verdaccio-auth-memory": "^9.3.0", "verdaccio-memory": "^9.3.0", "verdaccio": "^4.4.4" diff --git a/packages/api/package.json b/packages/api/package.json index 4a1ed436f..590cb7c47 100644 --- a/packages/api/package.json +++ b/packages/api/package.json @@ -27,6 +27,7 @@ "@verdaccio/dev-commons": "5.0.0-alpha.0", "@verdaccio/hooks": "5.0.0-alpha.0", "@verdaccio/logger": "5.0.0-alpha.0", + "@verdaccio/auth": "5.0.0-alpha.0", "@verdaccio/middleware": "5.0.0-alpha.0", "@verdaccio/utils": "5.0.0-alpha.0", "body-parser": "^1.19.0", diff --git a/packages/auth/package.json b/packages/auth/package.json index f4ef972bf..1aee03aab 100644 --- a/packages/auth/package.json +++ b/packages/auth/package.json @@ -26,13 +26,12 @@ "@verdaccio/commons-api": "^9.0.0", "@verdaccio/dev-commons": "5.0.0-alpha.0", "@verdaccio/loaders": "5.0.0-alpha.0", + "@verdaccio/logger": "5.0.0-alpha.0", "@verdaccio/utils": "5.0.0-alpha.0", - "bunyan": "1.8.12", "express": "^4.17.1", "lodash": "^4.17.15" }, "devDependencies": { - "@types/bunyan": "1.8.6", "@verdaccio/dev-types": "5.0.0-alpha.0" }, "gitHead": "7c246ede52ff717707fcae66dd63fc4abd536982" diff --git a/packages/auth/src/auth.ts b/packages/auth/src/auth.ts index ac7a0214d..c049b446f 100644 --- a/packages/auth/src/auth.ts +++ b/packages/auth/src/auth.ts @@ -61,7 +61,7 @@ class Auth implements IAuth { } private _applyDefaultPlugins(): void { - this.plugins.push(getDefaultPlugins()); + this.plugins.push(getDefaultPlugins(this.logger)); } public changePassword(username: string, password: string, newPassword: string, cb: Callback): void { diff --git a/packages/cli/src/cli.ts b/packages/cli/src/cli.ts index a96e4aa6f..52ce0f2c7 100644 --- a/packages/cli/src/cli.ts +++ b/packages/cli/src/cli.ts @@ -23,9 +23,6 @@ if (isVersionValid()) { process.title = 'verdaccio'; -// default setup -setup(null, {logStart: false}); - const pkgVersion = '5.0.0'; const pkgName = 'verdaccio'; diff --git a/packages/cli/src/commands/init.ts b/packages/cli/src/commands/init.ts index d439a9646..7dedaa599 100644 --- a/packages/cli/src/commands/init.ts +++ b/packages/cli/src/commands/init.ts @@ -3,12 +3,14 @@ import _ from 'lodash'; import { parseConfigFile} from "@verdaccio/utils"; import { findConfigFile } from "@verdaccio/config"; -import { logger } from '@verdaccio/logger'; +import { logger, createLogger } from '@verdaccio/logger'; import {startVerdaccio, listenDefaultCallback} from "@verdaccio/node-api"; export const DEFAULT_PROCESS_NAME: string = 'verdaccio'; export default function initProgram(commander, pkgVersion, pkgName) { + // FIXME: we need to log before the setup is being applied + // const initLogger = createLogger(); const cliListener = commander.listen; let configPathLocation; let verdaccioConfiguration; @@ -32,11 +34,11 @@ export default function initProgram(commander, pkgVersion, pkgName) { }); } - logger.warn({file: configPathLocation}, 'config file - @{file}'); + // initLogger.warn({file: configPathLocation}, 'config file - @{file}'); startVerdaccio(verdaccioConfiguration, cliListener, configPathLocation, pkgVersion, pkgName, listenDefaultCallback); } catch (err) { - logger.fatal({file: configPathLocation, err: err}, 'cannot open config file @{file}: @{!err.message}'); + // initLogger.fatal({file: configPathLocation, err: err}, 'cannot open config file @{file}: @{!err.message}'); process.exit(1); } } diff --git a/packages/commons/src/constants.ts b/packages/commons/src/constants.ts index b6e5a26a3..645e2393d 100644 --- a/packages/commons/src/constants.ts +++ b/packages/commons/src/constants.ts @@ -161,3 +161,7 @@ export const STORAGE = { NO_SUCH_FILE_ERROR: 'ENOENT', DEFAULT_REVISION: '0-0000000000000000' }; + +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}`; diff --git a/packages/config/package.json b/packages/config/package.json index d4bd8c5c0..2065969a9 100644 --- a/packages/config/package.json +++ b/packages/config/package.json @@ -23,10 +23,8 @@ "build": "npm run build:js && npm run build:types" }, "dependencies": { + "@verdaccio/logger": "5.0.0-alpha.0", "@verdaccio/utils": "5.0.0-alpha.0" }, - "devDependencies": { - "@types/bunyan": "1.8.6" - }, "gitHead": "7c246ede52ff717707fcae66dd63fc4abd536982" } diff --git a/packages/config/src/conf/default.yaml b/packages/config/src/conf/default.yaml index a4c5cac5a..66e90f5f8 100644 --- a/packages/config/src/conf/default.yaml +++ b/packages/config/src/conf/default.yaml @@ -10,6 +10,8 @@ storage: ./storage # path to a directory with plugins to include plugins: ./plugins +# print logs +# logs: ./logs web: title: Verdaccio @@ -72,7 +74,19 @@ middlewares: enabled: true # log settings -logs: { type: stdout, format: pretty, level: http } +logs: + # Logger as STDOUT + { type: stdout, format: pretty, level: http } + # Logger as STDOUT as JSON + # { type: stdout, format: json, level: http } + # Logger as STDOUT as JSON + # { type: stdout, format: pretty-timestamped, level: http } + # Logger as STDOUT as custom prettifier + # { type: stdout, plugin: { dest: '@verdaccio/logger-prettify' : options: { foo: 1, bar: 2}}, level: http } + # Logger as file + # { type: file, path: verdaccio.log, level: http} + # FIXME: this should be documented + # More info about log rotation https://github.com/pinojs/pino/blob/master/docs/help.md#log-rotation #experiments: # # support for npm token command diff --git a/packages/config/src/conf/docker.yaml b/packages/config/src/conf/docker.yaml index a98043b1d..deb589904 100644 --- a/packages/config/src/conf/docker.yaml +++ b/packages/config/src/conf/docker.yaml @@ -66,18 +66,25 @@ packages: # if package is not available locally, proxy requests to 'npmjs' registry proxy: npmjs -# You can specify HTTP/1.1 server keep alive timeout in seconds for incoming connections. -# A value of 0 makes the http server behave similarly to Node.js versions prior to 8.0.0, which did not have a keep-alive timeout. -# WORKAROUND: Through given configuration you can workaround following issue https://github.com/verdaccio/verdaccio/issues/301. Set to 0 in case 60 is not enough. -server: - keepAliveTimeout: 60 - middlewares: audit: enabled: true # log settings -logs: { type: stdout, format: pretty, level: http } +# log settings +logs: + # Logger as STDOUT + { type: stdout, format: pretty, level: http } + # Logger as STDOUT as JSON + # { type: stdout, format: json, level: http } + # Logger as STDOUT as JSON + # { type: stdout, format: pretty-timestamped, level: http } + # Logger as STDOUT as custom prettifier + # { type: stdout, plugin: { dest: '@verdaccio/logger-prettify' : options: { foo: 1, bar: 2}}, level: http } + # Logger as file + # { type: file, path: verdaccio.log, level: http} + # FIXME: this should be documented +# More info about log rotation https://github.com/pinojs/pino/blob/master/docs/help.md#log-rotation #experiments: # # support for npm token command diff --git a/packages/config/src/config-path.ts b/packages/config/src/config-path.ts index 9ab9bfa62..5f06aab13 100644 --- a/packages/config/src/config-path.ts +++ b/packages/config/src/config-path.ts @@ -13,7 +13,9 @@ const XDG = 'xdg'; const WIN = 'win'; const WIN32 = 'win32'; // eslint-disable-next-line -const pkgJSON = require('../package.json'); +const pkgJSON = { + name: 'verdaccio' +}; export type SetupDirectory = { path: string; diff --git a/packages/config/test/config.spec.ts b/packages/config/test/config.spec.ts index e09618028..a70836530 100644 --- a/packages/config/test/config.spec.ts +++ b/packages/config/test/config.spec.ts @@ -54,6 +54,7 @@ const checkDefaultConfPackages = (config) => { expect(config.middlewares.audit).toBeDefined(); expect(config.middlewares.audit.enabled).toBeTruthy(); // logs + expect(config.logs).toBeDefined(); expect(config.logs.type).toEqual('stdout'); expect(config.logs.format).toEqual('pretty'); expect(config.logs.level).toEqual('http'); diff --git a/packages/logger-prettify/.babelrc b/packages/logger-prettify/.babelrc new file mode 100644 index 000000000..28397a1bd --- /dev/null +++ b/packages/logger-prettify/.babelrc @@ -0,0 +1,3 @@ +{ + "presets": [["@verdaccio"]] +} diff --git a/packages/logger-prettify/.eslintrc b/packages/logger-prettify/.eslintrc new file mode 100644 index 000000000..5cc0de02f --- /dev/null +++ b/packages/logger-prettify/.eslintrc @@ -0,0 +1,8 @@ +{ + "extends": [ + "@verdaccio" + ], + "rules": { + "guard-for-in": 0 + } +} diff --git a/packages/logger-prettify/jest.config.js b/packages/logger-prettify/jest.config.js new file mode 100644 index 000000000..ae0866389 --- /dev/null +++ b/packages/logger-prettify/jest.config.js @@ -0,0 +1,4 @@ +const config = require('../../jest/config'); + +module.exports = Object.assign({}, config, {}); + diff --git a/packages/logger-prettify/package.json b/packages/logger-prettify/package.json new file mode 100644 index 000000000..06f0041c5 --- /dev/null +++ b/packages/logger-prettify/package.json @@ -0,0 +1,43 @@ +{ + "name": "@verdaccio/logger-prettify", + "version": "5.0.0-alpha.0", + "description": "logger", + "main": "./build/index.js", + "types": "build/index.d.ts", + "author": { + "name": "Juan Picado", + "email": "juanpicado19@gmail.com" + }, + "repository": { + "type": "git", + "url": "git://github.com/verdaccio/verdaccio" + }, + "license": "MIT", + "homepage": "https://verdaccio.org", + "scripts": { + "clean": "rimraf ./build", + "test": "cross-env NODE_ENV=test BABEL_ENV=test jest", + "type-check": "tsc --noEmit", + "lint": "yarn type-check && eslint \"@(src|tests)/**\"", + "build:types": "tsc --emitDeclarationOnly --declaration true", + "build:js": "cross-env BABEL_ENV=registry babel src/ --out-dir build/ --copy-files --extensions \".ts,.tsx\" --source-maps", + "build": "npm run build:js && npm run build:types" + }, + "dependencies": { + "@verdaccio/dev-commons": "5.0.0-alpha.0", + "@verdaccio/commons-api": "^9.4.0", + "dayjs": "^1.8.19", + "lodash": "^4.17.15", + "pad-right": "0.2.2", + "pad-left": "2.1.0", + "prettier-bytes": "^1.0.3", + "pretty-ms": "^5.0.0", + "fast-safe-stringify": "^2.0.7", + "kleur": "^3.0.3" + }, + "devDependencies": { + "@types/pino": "^5.17.0", + "pino": "^5.14.0" + }, + "gitHead": "7c246ede52ff717707fcae66dd63fc4abd536982" +} diff --git a/packages/logger-prettify/src/formatter.ts b/packages/logger-prettify/src/formatter.ts new file mode 100644 index 000000000..f1023b1c2 --- /dev/null +++ b/packages/logger-prettify/src/formatter.ts @@ -0,0 +1,85 @@ +import { inspect } from 'util'; + +import { white, red, green } from 'kleur'; +import padLeft from 'pad-left'; + +import {calculateLevel, LevelCode, levelsColors, subSystemLevels} from "./levels"; +import {formatLoggingDate, isObject, pad} from './utils'; +import {PrettyOptionsExtended} from "./types"; + +let LEVEL_VALUE_MAX = 0; +for (const l in levelsColors) { + LEVEL_VALUE_MAX = Math.max(LEVEL_VALUE_MAX, l.length); +} + +const ERROR_FLAG = '!'; + +export interface ObjectTemplate { + level: LevelCode; + msg: string; + sub?: string; + [key: string]: string | number | object | null | void; +}; + +export function fillInMsgTemplate(msg, templateOptions: ObjectTemplate, colors): string { + const templateRegex = /@{(!?[$A-Za-z_][$0-9A-Za-z\._]*)}/g; + + return msg.replace(templateRegex, (_, name): string => { + + let str = templateOptions; + let isError; + if (name[0] === ERROR_FLAG) { + name = name.substr(1); + isError = true; + } + + // object can be @{foo.bar.} + const listAccessors = name.split('.'); + for (let property = 0; property < listAccessors.length; property++) { + const id = listAccessors[property]; + if (isObject(str)) { + str = (str as object)[id]; + } + } + + if (typeof str === 'string') { + if (colors === false || (str as string).includes('\n')) { + return str; + } else if (isError) { + return red(str); + } + return green(str); + } + + // object, showHidden, depth, colors + return inspect(str, undefined, null, colors); + }); +} + +const CUSTOM_PAD_LENGTH = 1; + +function getMessage(debugLevel, msg, sub, templateObjects, hasColors) { + const finalMessage = fillInMsgTemplate(msg, templateObjects, hasColors); + + const subSystemType = subSystemLevels.color[sub ?? 'default']; + if (hasColors) { + const logString = `${levelsColors[debugLevel](pad(debugLevel, LEVEL_VALUE_MAX))}${white(`${subSystemType} ${finalMessage}`)}`; + + return padLeft(logString, logString.length + CUSTOM_PAD_LENGTH , ' '); + } + const logString = `${pad(debugLevel, LEVEL_VALUE_MAX)}${subSystemType} ${finalMessage}`; + + return padLeft(logString, logString.length + CUSTOM_PAD_LENGTH , ' '); +} + +export function printMessage( + templateObjects: ObjectTemplate, + options: PrettyOptionsExtended, + hasColors = true): string { + const { prettyStamp } = options; + const { level, msg, sub } = templateObjects; + const debugLevel = calculateLevel(level); + const logMessage = getMessage(debugLevel, msg, sub, templateObjects, hasColors); + + return prettyStamp ? formatLoggingDate(templateObjects.time as number, logMessage) : logMessage; +} diff --git a/packages/logger-prettify/src/index.ts b/packages/logger-prettify/src/index.ts new file mode 100644 index 000000000..5c4be0780 --- /dev/null +++ b/packages/logger-prettify/src/index.ts @@ -0,0 +1,18 @@ +import { printMessage } from "./formatter"; +import {PrettyOptionsExtended} from "./types"; + +export type PrettyFactory = (param) => string; + +/* + options eg: + { messageKey: 'msg', levelFirst: true, prettyStamp: false } + */ + +module.exports = function prettyFactory (options: PrettyOptionsExtended): PrettyFactory { + // the break line must happens in the prettify component + const breakLike = '\n'; + return (inputData): string => { + // FIXME: review colors by default is true + return printMessage(inputData, options, true) + breakLike; + }; +}; diff --git a/packages/logger/src/levels.ts b/packages/logger-prettify/src/levels.ts similarity index 50% rename from packages/logger/src/levels.ts rename to packages/logger-prettify/src/levels.ts index 1defad37e..0b260f190 100644 --- a/packages/logger/src/levels.ts +++ b/packages/logger-prettify/src/levels.ts @@ -1,4 +1,4 @@ -import { yellow, green, red, magenta, black, blue, cyan, white } from 'kleur'; +import { yellow, green, black, blue, red, magenta, cyan, white } from 'kleur'; export type LogLevel = 'trace' | 'debug' | 'info' | 'http' | 'warn' | 'error' | 'fatal'; @@ -6,20 +6,18 @@ export type LevelCode = number; export function calculateLevel(levelCode: LevelCode): LogLevel { switch (true) { - case levelCode === 10: + case levelCode < 15: return 'trace'; - case levelCode === 20: + case levelCode < 25: return 'debug'; - case levelCode === 25: - return 'http'; - case levelCode === 30: + case levelCode < 35: return 'info'; - case levelCode === 40: + case levelCode == 35: + return 'http'; + case levelCode < 45: return 'warn'; - case levelCode === 50: + case levelCode < 55: return 'error'; - case levelCode === 60: - return 'fatal'; default: return 'fatal'; } @@ -36,23 +34,23 @@ export const levelsColors = { }; enum ARROWS { - LEFT = '<--', - RIGHT = '-->', - EQUAL = '-=-', - NEUTRAL = '---' + LEFT = '<--', + RIGHT = '-->', + EQUAL = '-=-', + NEUTRAL = '---' } export const subSystemLevels = { - color: { - in: green(ARROWS.LEFT), - out: yellow(ARROWS.RIGHT), - fs: black(ARROWS.EQUAL), - default: blue(ARROWS.NEUTRAL), - }, - white: { - in: ARROWS.LEFT, - out: ARROWS.RIGHT, - fs: ARROWS.EQUAL, - default: ARROWS.NEUTRAL, - }, + color: { + in: green(ARROWS.LEFT), + out: yellow(ARROWS.RIGHT), + fs: black(ARROWS.EQUAL), + default: blue(ARROWS.NEUTRAL), + }, + white: { + in: ARROWS.LEFT, + out: ARROWS.RIGHT, + fs: ARROWS.EQUAL, + default: ARROWS.NEUTRAL, + }, }; diff --git a/packages/logger-prettify/src/types.ts b/packages/logger-prettify/src/types.ts new file mode 100644 index 000000000..afd004a18 --- /dev/null +++ b/packages/logger-prettify/src/types.ts @@ -0,0 +1,5 @@ +import {PrettyOptions} from "pino"; + +export interface PrettyOptionsExtended extends PrettyOptions { + prettyStamp: boolean; +} diff --git a/packages/logger-prettify/src/utils.ts b/packages/logger-prettify/src/utils.ts new file mode 100644 index 000000000..138c7e00a --- /dev/null +++ b/packages/logger-prettify/src/utils.ts @@ -0,0 +1,19 @@ +import _ from 'lodash'; +import padRight from 'pad-right'; +import dayjs from 'dayjs'; + +export const FORMAT_DATE = 'YYYY-MM-DD HH:mm:ss'; + +export function isObject(obj: unknown): boolean { + return _.isObject(obj) && _.isNull(obj) === false && _.isArray(obj) === false; +} + +export function pad(str: string, max: number): string { + return padRight(str, max, ' '); +} + +export function formatLoggingDate(time: number, message): string { + const timeFormatted = dayjs(time).format(FORMAT_DATE); + + return `[${timeFormatted}]${message}`; +} diff --git a/packages/logger-prettify/test/__snapshots__/formatter.spec.ts.snap b/packages/logger-prettify/test/__snapshots__/formatter.spec.ts.snap new file mode 100644 index 000000000..44330fe8b --- /dev/null +++ b/packages/logger-prettify/test/__snapshots__/formatter.spec.ts.snap @@ -0,0 +1,21 @@ +// Jest Snapshot v1, https://goo.gl/fbAQLP + +exports[`formatter printMessage should display a bytes request 1`] = `" http <-- 200, user: null(127.0.0.1), req: 'GET /verdaccio', bytes: 0/150186"`; + +exports[`formatter printMessage should display a resource request 1`] = `" info <-- 127.0.0.1 requested 'GET /verdaccio'"`; + +exports[`formatter printMessage should display a streaming request 1`] = `" http --> 304, req: 'GET https://registry.npmjs.org/verdaccio' (streaming)"`; + +exports[`formatter printMessage should display an error request 1`] = `" error--> ERR, req: 'GET https://registry.fake.org/aaa', error: getaddrinfo ENOTFOUND registry.fake.org"`; + +exports[`formatter printMessage should display an fatal request 1`] = `" fatal--> ERR, req: 'GET https://registry.fake.org/aaa', error: fatal error"`; + +exports[`formatter printMessage should display config file 1`] = `" warn --- config file - /Users/user/.config/verdaccio/config/config.yaml"`; + +exports[`formatter printMessage should display custom log message 1`] = `" debug--- custom - foo - undefined"`; + +exports[`formatter printMessage should display trace level 1`] = `" trace--- [trace] - foo"`; + +exports[`formatter printMessage should display trace level with pretty stamp 1`] = `"[formatted-date] trace--- [trace] - foo"`; + +exports[`formatter printMessage should display version and http address 1`] = `" warn --- http address - http://localhost:4873/ - verdaccio/5.0.0"`; diff --git a/packages/logger-prettify/test/__snapshots__/index.spec.ts.snap b/packages/logger-prettify/test/__snapshots__/index.spec.ts.snap new file mode 100644 index 000000000..94d4f6be5 --- /dev/null +++ b/packages/logger-prettify/test/__snapshots__/index.spec.ts.snap @@ -0,0 +1,6 @@ +// Jest Snapshot v1, https://goo.gl/fbAQLP + +exports[`prettyFactory should return a function 1`] = ` +" trace--- [trace] - foo +" +`; diff --git a/packages/logger-prettify/test/formatter.spec.ts b/packages/logger-prettify/test/formatter.spec.ts new file mode 100644 index 000000000..42ebbddca --- /dev/null +++ b/packages/logger-prettify/test/formatter.spec.ts @@ -0,0 +1,213 @@ +import {printMessage} from "../src/formatter"; +import {LevelCode} from "../src/levels"; + +jest.mock('dayjs', () => ({ + __esModule: true, + default: () => ({ + format: () => 'formatted-date' + }) +})); + +describe('formatter', () => { + const prettyfierOptions = {messageKey: 'msg', levelFirst: true, prettyStamp: false}; + describe('printMessage', () => { + test('should display config file', () => { + const log = { + level: 40, + time: 1585410824129, + v: 1, + pid: 27029, + hostname: 'localhost', + file: '/Users/user/.config/verdaccio/config/config.yaml', + msg: 'config file - @{file}' + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display trace level', () => { + const log = { + level: 10, + foo: 'foo', + msg: '[trace] - @{foo}' + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display trace level with pretty stamp', () => { + const log = { + level: 10, + foo: 'foo', + time: 1585411248203, + msg: '[trace] - @{foo}' + }; + + expect(printMessage(log, Object.assign({}, prettyfierOptions, { + prettyStamp: true + }))).toMatchSnapshot(); + }); + + test('should display a bytes request', () => { + const log = { + level: 35, + time: 1585411248203, + v: 1, + pid: 27029, + hostname: 'macbook-touch', + sub: 'in', + request: {method: 'GET', url: '/verdaccio'}, + user: null, + remoteIP: '127.0.0.1', + status: 200, + error: undefined, + bytes: {in: 0, out: 150186}, + msg: "@{status}, user: @{user}(@{remoteIP}), req: '@{request.method} @{request.url}', bytes: @{bytes.in}/@{bytes.out}" + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display an error request', () => { + const log = { + level: 54, + time: 1585416029123, + v: 1, + pid: 30032, + hostname: 'macbook-touch', + sub: 'out', + err: { + type: 'Error', + message: 'getaddrinfo ENOTFOUND registry.fake.org', + stack: 'Error: getaddrinfo ENOTFOUND registry.fake.org\n' + + ' at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26)', + errno: -3008, + code: 'ENOTFOUND', + syscall: 'getaddrinfo', + hostname: 'registry.fake.org' + }, + request: {method: 'GET', url: 'https://registry.fake.org/aaa'}, + status: 'ERR', + error: 'getaddrinfo ENOTFOUND registry.fake.org', + bytes: {in: 0, out: 0}, + msg: "@{!status}, req: '@{request.method} @{request.url}', error: @{!error}" + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display an fatal request', () => { + const log = { + level: 60, + time: 1585416029123, + v: 1, + pid: 30032, + hostname: 'macbook-touch', + sub: 'out', + err: { + type: 'Error', + message: 'fatal error', + stack: '....', + errno: -3008, + code: 'ENOTFOUND', + }, + request: {method: 'GET', url: 'https://registry.fake.org/aaa'}, + status: 'ERR', + error: 'fatal error', + bytes: {in: 0, out: 0}, + msg: "@{!status}, req: '@{request.method} @{request.url}', error: @{!error}" + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display a streaming request', () => { + const log = { + level: 35, + time: 1585411247920, + v: 1, + pid: 27029, + hostname: 'macbook-touch', + sub: 'out', + request: {method: 'GET', url: 'https://registry.npmjs.org/verdaccio'}, + status: 304, + msg: "@{!status}, req: '@{request.method} @{request.url}' (streaming)" + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display version and http address', () => { + const log = { + level: 40, + time: 1585410824322, + v: 1, + pid: 27029, + hostname: 'macbook-touch', + addr: 'http://localhost:4873/', + version: 'verdaccio/5.0.0', + msg: 'http address - @{addr} - @{version}' + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + test('should display custom log message', () => { + const level: LevelCode = 15; + const log = { + level, + something: 'foo', + msg: 'custom - @{something} - @{missingParam}' + }; + + expect(printMessage(log, prettyfierOptions)).toMatchSnapshot(); + }); + + // test('should handle undefined object', () => { + // const log = { + // level: 15, + // something: 'foo', + // msg: 'custom - @{something} - @{missingParam}' + // }; + // + // expect(printMessage(undefined, undefined, undefined)).toMatchSnapshot(); + // }); + + test('should display a resource request', () => { + const log = { + level: 30, + time: 1585411247622, + v: 1, + pid: 27029, + hostname: 'macbook-touch', + sub: 'in', + req: { + id: undefined, + method: 'GET', + url: '/verdaccio', + headers: { + connection: 'keep-alive', + 'user-agent': 'npm/6.13.2 node/v13.1.0 darwin x64', + 'npm-in-ci': 'false', + 'npm-scope': '', + 'npm-session': 'afebb4748178bd4b', + referer: 'view verdaccio', + 'pacote-req-type': 'packument', + 'pacote-pkg-id': 'registry:verdaccio', + accept: 'application/json', + authorization: '', + 'if-none-match': '"fd6440ba2ad24681077664d8f969e5c3"', + 'accept-encoding': 'gzip,deflate', + host: 'localhost:4873' + }, + remoteAddress: '127.0.0.1', + remotePort: 57968, + }, + ip: '127.0.0.1', + msg: "@{ip} requested '@{req.method} @{req.url}'" + }; + + expect(printMessage(log, prettyfierOptions, false)).toMatchSnapshot(); + }); + }); +}); diff --git a/packages/logger-prettify/test/index.spec.ts b/packages/logger-prettify/test/index.spec.ts new file mode 100644 index 000000000..6ba7677ad --- /dev/null +++ b/packages/logger-prettify/test/index.spec.ts @@ -0,0 +1,18 @@ +import * as factory from '../src'; + +describe('prettyFactory', () => { + const prettyfierOptions = { messageKey: 'msg', levelFirst: true, prettyStamp: false }; + test('should return a function', () => { + expect(typeof factory['default']({})).toEqual('function') + }); + + test('should return a function', () => { + const log = { + level: 10, + foo: 'foo', + msg: '[trace] - @{foo}' + }; + + expect(factory['default'](prettyfierOptions)(log)).toMatchSnapshot(); + }); +}); diff --git a/packages/logger-prettify/tsconfig.json b/packages/logger-prettify/tsconfig.json new file mode 100644 index 000000000..a9539c625 --- /dev/null +++ b/packages/logger-prettify/tsconfig.json @@ -0,0 +1,10 @@ +{ + "extends": "../../tsconfig", + "compilerOptions": { + "rootDir": "./src", + "outDir": "./build", + "allowSyntheticDefaultImports": true + }, + "include": ["src/**/*"], + "exclude": ["src/**/*.test.ts"] +} diff --git a/packages/logger/jest.config.js b/packages/logger/jest.config.js index ae0866389..911a886b0 100644 --- a/packages/logger/jest.config.js +++ b/packages/logger/jest.config.js @@ -1,4 +1,6 @@ const config = require('../../jest/config'); -module.exports = Object.assign({}, config, {}); +module.exports = Object.assign({}, config, { + verbose: true, +}); diff --git a/packages/logger/package.json b/packages/logger/package.json index f63029773..e90e40d92 100644 --- a/packages/logger/package.json +++ b/packages/logger/package.json @@ -16,20 +16,20 @@ "homepage": "https://verdaccio.org", "scripts": { "clean": "rimraf ./build", - "test": "cross-env NODE_ENV=test BABEL_ENV=test jest", + "test": "cross-env NODE_ENV=test BABEL_ENV=test jest --runTestsByPath", "type-check": "tsc --noEmit", "build:types": "tsc --emitDeclarationOnly --declaration true", "build:js": "cross-env BABEL_ENV=registry babel src/ --out-dir build/ --copy-files --extensions \".ts,.tsx\" --source-maps", "build": "npm run build:js && npm run build:types" }, "dependencies": { - "bunyan": "1.8.12", - "dayjs": "1.8.19", - "http-errors": "1.7.3", - "kleur": "3.0.3" + "@verdaccio/logger-prettify": "5.0.0-alpha.0", + "pino": "^5.17.0", + "lodash": "^4.17.15" }, "devDependencies": { - "@types/bunyan": "1.8.6" + "@verdaccio/types": "^9.3.0", + "@types/pino": "^5.17.0" }, "gitHead": "7c246ede52ff717707fcae66dd63fc4abd536982" } diff --git a/packages/logger/src/format/json.ts b/packages/logger/src/format/json.ts deleted file mode 100644 index 2177843f6..000000000 --- a/packages/logger/src/format/json.ts +++ /dev/null @@ -1,9 +0,0 @@ -import { fillInMsgTemplate } from '../formatter'; - -const Logger = require('bunyan'); - -export function jsonFormat(obj, hasColors): string { - const msg = fillInMsgTemplate(obj.msg, obj, hasColors); - - return `${JSON.stringify({ ...obj, msg }, Logger.safeCycles())}\n`; -} diff --git a/packages/logger/src/format/pretty-timestamped.ts b/packages/logger/src/format/pretty-timestamped.ts deleted file mode 100644 index 6ee7fa64a..000000000 --- a/packages/logger/src/format/pretty-timestamped.ts +++ /dev/null @@ -1,6 +0,0 @@ -import { formatLoggingDate } from '../utils'; -import { printMessage } from '../formatter'; - -export function prettyTimestamped(obj, hasColors): string { - return `[${formatLoggingDate(obj.time)}] ${printMessage(obj.level, obj.msg, obj, hasColors)}\n`; -} diff --git a/packages/logger/src/format/pretty.ts b/packages/logger/src/format/pretty.ts deleted file mode 100644 index e4bd27bb7..000000000 --- a/packages/logger/src/format/pretty.ts +++ /dev/null @@ -1,5 +0,0 @@ -import { printMessage } from '../formatter'; - -export function pretty(obj, hasColors): string { - return `${printMessage(obj.level, obj.msg, obj, hasColors)}\n`; -} diff --git a/packages/logger/src/formatter.ts b/packages/logger/src/formatter.ts deleted file mode 100644 index 83c67b1e1..000000000 --- a/packages/logger/src/formatter.ts +++ /dev/null @@ -1,68 +0,0 @@ -import { inspect } from 'util'; - -import { white, red, green } from 'kleur'; -import {calculateLevel, levels, subsystems} from "./levels"; - -import { isObject, pad } from './utils'; - -let LEVEL_VALUE_MAX = 0; -for (const l in levels) { - if (Object.prototype.hasOwnProperty.call(levels, l)) { - LEVEL_VALUE_MAX = Math.max(LEVEL_VALUE_MAX, l.length); - } -} - -/** - * Apply colors to a string based on level parameters. - * @param {*} type - * @param {*} msg - * @param {*} templateObjects - * @param {*} hasColors - * @return {String} - */ -export function printMessage(type, msg, templateObjects, hasColors) { - if (typeof type === 'number') { - type = calculateLevel(type); - } - - const finalMessage = fillInMsgTemplate(msg, templateObjects, hasColors); - - const sub = subsystems[hasColors ? 0 : 1][templateObjects.sub] || subsystems[+!hasColors].default; - if (hasColors) { - return ` ${levels[type](pad(type, LEVEL_VALUE_MAX))}${white(`${sub} ${finalMessage}`)}`; - } - return ` ${pad(type, LEVEL_VALUE_MAX)}${sub} ${finalMessage}`; -} - -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); - } - return green(str); - } - return inspect(str, undefined, null, colors); - }); -} diff --git a/packages/logger/src/index.ts b/packages/logger/src/index.ts index 4445c47a1..f1c958568 100644 --- a/packages/logger/src/index.ts +++ b/packages/logger/src/index.ts @@ -1 +1,2 @@ -export { setup, logger } from './logger'; +export { setup, createLogger, logger } from './logger'; + diff --git a/packages/logger/src/logger.ts b/packages/logger/src/logger.ts index c64d9e80d..586be3823 100644 --- a/packages/logger/src/logger.ts +++ b/packages/logger/src/logger.ts @@ -1,166 +1,116 @@ -/* eslint-disable */ +import pino from 'pino'; +import _ from 'lodash'; -const cluster = require('cluster'); -const Logger = require('bunyan'); -const Error = require('http-errors'); -const Stream = require('stream'); -const _ = require('lodash'); +const DEFAULT_LOG_FORMAT = 'pretty'; -const pkgJSON = require('../package.json'); +export let logger; - -import {prettyTimestamped} from "./format/pretty-timestamped"; -import {pretty} from "./format/pretty"; -import {jsonFormat} from "./format/json"; - -/** - * A RotatingFileStream that modifies the message first - */ -class VerdaccioRotatingFileStream extends Logger.RotatingFileStream { - // We depend on mv so that this is there - write(obj) { - super.write(jsonFormat(obj, false)); - } - - rotate(): void { - super.rotate(); - this.emit('rotated'); - } +function getPrettifier() { + // TODO: this module can be loaded dynamically and allow custom formatting + return require('@verdaccio/logger-prettify'); } -let logger; +export type LogPlugin = { + dest: string; + options?: any[]; +}; -export interface LoggerTarget { - type?: string; - format?: string; - level?: string; - options?: any; - path?: string; +export type LogType = 'file' | 'stdout'; +export type LogFormat = 'json' | 'pretty-timestamped' | 'pretty'; + +export function createLogger(options = {}, + destination = pino.destination(1), + format: LogFormat = DEFAULT_LOG_FORMAT, + prettyPrintOptions = {}) { + if (_.isNil(format)) { + format = DEFAULT_LOG_FORMAT; + } + + let pinoConfig = { + ...options, + customLevels: { + http: 35 + }, + serializers: { + err: pino.stdSerializers.err, + req: pino.stdSerializers.req, + res: pino.stdSerializers.res + }, + }; + + if (format === DEFAULT_LOG_FORMAT || format !== 'json') { + pinoConfig = Object.assign({}, pinoConfig, { + prettyPrint: { + levelFirst: true, + prettyStamp: format === 'pretty-timestamped', + ...prettyPrintOptions + }, + prettifier: getPrettifier(), + } + ) + } + + return pino(pinoConfig, destination); } -const DEFAULT_LOGGER_CONF = [{ type: 'stdout', format: 'pretty', level: 'http' }]; +export function getLogger() { + if (_.isNil(logger)) { + console.warn('logger is not defined'); + return; + } -/** - * Setup the Buyan logger - * @param {*} logs list of log configuration - */ -function setup(logs, { logStart } = { logStart: true }) { - const streams: any = []; - if (logs == null) { - logs = DEFAULT_LOGGER_CONF; - } - - logs.forEach(function(target: LoggerTarget) { - let level = target.level || 35; - if (level === 'http') { - level = 35; - } - - // create a stream for each log configuration - if (target.type === 'rotating-file') { - if (target.format !== 'json') { - throw new Error('Rotating file streams only work with JSON!'); - } - if (cluster.isWorker) { - // https://github.com/trentm/node-bunyan#stream-type-rotating-file - throw new Error('Cluster mode is not supported for rotating-file!'); - } - - const stream = new VerdaccioRotatingFileStream( - // @ts-ignore - _.merge( - {}, - // Defaults can be found here: https://github.com/trentm/node-bunyan#stream-type-rotating-file - target.options || {}, - { path: target.path, level } - ) - ); - - const rotateStream = { - type: 'raw', - level, - stream, - }; - - if (logStart) { - stream.on('rotated', () => logger.warn('Start of logfile')); - } - - streams.push(rotateStream); - } else { - const stream = new Stream(); - stream.writable = true; - - let destination; - let destinationIsTTY = false; - if (target.type === 'file') { - // destination stream - destination = require('fs').createWriteStream(target.path, { flags: 'a', encoding: 'utf8' }); - destination.on('error', function(err) { - stream.emit('error', err); - }); - } else if (target.type === 'stdout' || target.type === 'stderr') { - destination = target.type === 'stdout' ? process.stdout : process.stderr; - destinationIsTTY = destination.isTTY; - } else { - throw Error('wrong target type for a log'); - } - - if (target.format === 'pretty') { - // making fake stream for pretty printing - stream.write = obj => { - destination.write(pretty(obj, destinationIsTTY)); - }; - } else if (target.format === 'pretty-timestamped') { - // making fake stream for pretty printing - stream.write = obj => { - destination.write(prettyTimestamped(obj, destinationIsTTY)); - }; - } else { - stream.write = obj => { - destination.write(jsonFormat(obj, destinationIsTTY)); - }; - } - - streams.push({ - // @ts-ignore - type: 'raw', - // @ts-ignore - level, - // @ts-ignore - stream: stream, - }); - } - }); - - // buyan default configuration - logger = new Logger({ - name: pkgJSON.name, - streams: streams, - serializers: { - err: Logger.stdSerializers.err, - req: Logger.stdSerializers.req, - res: Logger.stdSerializers.res, - }, - }); - - // In case of an empty log file, we ensure there is always something logged. This also helps see if the server - // was restarted in any cases - if (logStart) { - logger.warn('Verdaccio started'); - } - - process.on('SIGUSR2', function() { - // https://github.com/trentm/node-bunyan#stream-type-rotating-file - if (logger) { - /** - * Note on log rotation: Often you may be using external log rotation utilities like logrotate on Linux or logadm - * on SmartOS/Illumos. In those cases, unless your are ensuring "copy and truncate" semantics - * (via copytruncate with logrotate or -c with logadm) then the fd for your 'file' stream will change. - */ - logger.reopenFileStreams(); - } - }); + return logger; } -export { setup, logger }; +const DEFAULT_LOGGER_CONF: LoggerConfigItem = { + type: 'stdout', + format: 'pretty', + level: 'http' +}; + +export type LoggerConfigItem = { + type?: LogType; + plugin?: LogPlugin; + format?: LogFormat; + path?: string; + level?: string; +} + +export type LoggerConfig = LoggerConfigItem[]; + +export function setup(options: LoggerConfig | LoggerConfigItem = [DEFAULT_LOGGER_CONF]) { + const isLegacyConf = _.isArray(options); + if (isLegacyConf) { + console.warn("DEPRECATE: logs does not have multi-stream support anymore, please upgrade your logger configuration"); + } + + // backward compatible, pick only the first option + let loggerConfig = isLegacyConf ? options[0] : options; + if (!loggerConfig?.level) { + loggerConfig = Object.assign({}, loggerConfig, { + level: 'http' + }) + } + + const pinoConfig = { level: loggerConfig.level }; + if (loggerConfig.type === 'file') { + logger = createLogger(pinoConfig, + pino.destination(loggerConfig.path), + loggerConfig.format); + } else if(loggerConfig.type === 'rotating-file') { + throw new Error('rotating-file type is not longer supported, consider use [logrotate] instead'); + } else { + logger = createLogger(pinoConfig, pino.destination(1), loggerConfig.format); + } + + process.on('uncaughtException', pino.final(logger, (err, finalLogger) => { + finalLogger.fatal(err, 'uncaughtException'); + process.exit(1); + })); + + // @ts-ignore + process.on('unhandledRejection', pino.final(logger, (err, finalLogger) => { + finalLogger.fatal(err, 'uncaughtException'); + process.exit(1); + })); +} diff --git a/packages/logger/src/utils.ts b/packages/logger/src/utils.ts deleted file mode 100644 index 742b42f7e..000000000 --- a/packages/logger/src/utils.ts +++ /dev/null @@ -1,29 +0,0 @@ -import dayjs from 'dayjs'; -import _ from 'lodash'; - -export const FORMAT_DATE = 'YYYY-MM-DD HH:mm:ss'; - -export function formatLoggingDate(time: string): string { - return dayjs(time).format(FORMAT_DATE); -} - -/** - * Check whether an element is an Object - * @param {*} obj the element - * @return {Boolean} - */ -export function isObject(obj: any): boolean { - return _.isObject(obj) && _.isNull(obj) === false && _.isArray(obj) === false; -} - -/** - * 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/packages/logger/test/logger.spec.ts b/packages/logger/test/logger.spec.ts new file mode 100644 index 000000000..c935253d1 --- /dev/null +++ b/packages/logger/test/logger.spec.ts @@ -0,0 +1,15 @@ +import { logger, setup } from "../src"; + + +describe('logger', () => { + test('dsadasd', () => { + const spyOn = jest.spyOn( process.stdout, 'write'); + setup([{ + level: 'info' + }]); + + logger.info({packageName: 'test'} , `publishing or updating a new version for @{packageName}`); + + // expect(spyOn).toHaveBeenCalledTimes(2); + }); +}); diff --git a/packages/logger/test/parser.spec.ts b/packages/logger/test/parser.spec.ts deleted file mode 100644 index 69c65d73d..000000000 --- a/packages/logger/test/parser.spec.ts +++ /dev/null @@ -1,121 +0,0 @@ -import { fillInMsgTemplate } from "../src/formatter"; -import {LOG_VERDACCIO_ERROR, LOG_VERDACCIO_BYTES} from "@verdaccio/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}]`, - yellow: r => `y[${r}]`, - black: r => `b[${r}]`, - blue: r => `bu[${r}]`, - red: r => `r[${r}]`, - cyan: r => `c[${r}]`, - magenta: r => `m[${r}]`, - white: r => `w[${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/packages/logger/verdaccio.log b/packages/logger/verdaccio.log new file mode 100644 index 000000000..9e4d5baf6 --- /dev/null +++ b/packages/logger/verdaccio.log @@ -0,0 +1 @@ +{"level":40,"time":1585491735899,"pid":71224,"hostname":"macbook-touch","packageName":"test","msg":"publishing or updating a new version for @{packageName}","v":1} diff --git a/packages/middleware/src/middleware.ts b/packages/middleware/src/middleware.ts index c9cd78aa5..b11262f04 100644 --- a/packages/middleware/src/middleware.ts +++ b/packages/middleware/src/middleware.ts @@ -176,6 +176,7 @@ export function final(body: FinalBody, req: $RequestExtend, res: $ResponseExtend res.send(body); } +// FIXME: deprecated, moved to @verdaccio/dev-commons 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}`; diff --git a/packages/node-api/src/bootstrap.ts b/packages/node-api/src/bootstrap.ts index c89549437..d3a6d73cd 100644 --- a/packages/node-api/src/bootstrap.ts +++ b/packages/node-api/src/bootstrap.ts @@ -8,7 +8,7 @@ import constants from 'constants'; import { Callback, ConfigWithHttps, HttpsConfKeyCert, HttpsConfPfx } from '@verdaccio/types'; import { API_ERROR, certPem, csrPem, keyPem } from '@verdaccio/dev-commons'; -import endPointAPI from '@verdaccio/server'; +import server from '@verdaccio/server'; import { logger} from '@verdaccio/logger'; import { getListListenAddresses, resolveConfigPath } from './cli-utils'; @@ -44,12 +44,11 @@ function startVerdaccio(config: any, cliListen: string, configPath: string, pkgV throw new Error(API_ERROR.CONFIG_BAD_FORMAT); } - if ('experiments' in config) { - displayExperimentsInfoBox(config.experiments); - } - - endPointAPI(config).then((app): void => { + server(config).then((app): void => { const addresses = getListListenAddresses(cliListen, config.listen); + if ('experiments' in config) { + displayExperimentsInfoBox(config.experiments); + } addresses.forEach(addr =>launchServer(app, addr, config, configPath, pkgName, pkgVersion, callback)); } diff --git a/packages/proxy/src/up-storage.ts b/packages/proxy/src/up-storage.ts index 7cb9335f5..3aa3e76b7 100644 --- a/packages/proxy/src/up-storage.ts +++ b/packages/proxy/src/up-storage.ts @@ -183,6 +183,7 @@ class ProxyStorage implements IProxy { */ function logActivity(): void { let message = "@{!status}, req: '@{request.method} @{request.url}'"; + // FIXME: use LOG_VERDACCIO_BYTES message += error ? ', error: @{!error}' : ', bytes: @{bytes.in}/@{bytes.out}'; self.logger.warn( { diff --git a/packages/store/src/storage.ts b/packages/store/src/storage.ts index 008c205db..652aeb120 100644 --- a/packages/store/src/storage.ts +++ b/packages/store/src/storage.ts @@ -41,7 +41,7 @@ class Storage implements IStorageHandler { public constructor(config: Config) { this.config = config; this.uplinks = setupUpLinks(config); - this.logger = logger; + this.logger = logger.child({module: 'storage'}); this.filters = []; // @ts-ignore this.localStorage = null; diff --git a/packages/utils/src/auth-utils.ts b/packages/utils/src/auth-utils.ts index 99a96785d..08fd87ed7 100644 --- a/packages/utils/src/auth-utils.ts +++ b/packages/utils/src/auth-utils.ts @@ -7,8 +7,6 @@ import { VerdaccioError } from '@verdaccio/commons-api'; import { ErrorCode } from './utils'; -import { logger } from '@verdaccio/logger'; - export function validatePassword(password: string, minLength: number = DEFAULT_MIN_LIMIT_PASSWORD): boolean { return typeof password === 'string' && password.length >= minLength; } @@ -65,7 +63,7 @@ export interface AuthPackageAllow extends PackageAccess, AllowAccess { export type ActionsAllowed = 'publish' | 'unpublish' | 'access'; -export function allow_action(action: ActionsAllowed): AllowAction { +export function allow_action(action: ActionsAllowed, logger): AllowAction { return function allowActionCallback(user: RemoteUser, pkg: AuthPackageAllow, callback: AllowActionCallback): void { logger.trace({remote: user.name}, `[auth/allow_action]: user: @{user.name}`); const { name, groups } = user; @@ -89,7 +87,7 @@ export function allow_action(action: ActionsAllowed): AllowAction { /** * */ -export function handleSpecialUnpublish(): any { +export function handleSpecialUnpublish(logger): any { return function(user: RemoteUser, pkg: AuthPackageAllow, callback: AllowActionCallback): void { const action = 'unpublish'; // verify whether the unpublish prop has been defined @@ -102,11 +100,11 @@ export function handleSpecialUnpublish(): any { } logger.trace({user: user.name, name: pkg.name, action, hasGroups}, `allow_action for @{action} for @{name} has groups: @{hasGroups} for @{user}`); - return allow_action(action)(user, pkg, callback); + return allow_action(action, logger)(user, pkg, callback); }; } -export function getDefaultPlugins(): IPluginAuth { +export function getDefaultPlugins(logger: any): IPluginAuth { return { authenticate(user: string, password: string, cb: Callback): void { cb(ErrorCode.getForbidden(API_ERROR.BAD_USERNAME_PASSWORD)); @@ -118,10 +116,10 @@ export function getDefaultPlugins(): IPluginAuth { // FIXME: allow_action and allow_publish should be in the @verdaccio/types // @ts-ignore - allow_access: allow_action('access'), + allow_access: allow_action('access', logger), // @ts-ignore - allow_publish: allow_action('publish'), - allow_unpublish: handleSpecialUnpublish(), + allow_publish: allow_action('publish', logger), + allow_unpublish: handleSpecialUnpublish(logger), }; } diff --git a/packages/utils/test/auth-utils.spec.ts b/packages/utils/test/auth-utils.spec.ts index 66ec83c14..06da1a8cb 100644 --- a/packages/utils/test/auth-utils.spec.ts +++ b/packages/utils/test/auth-utils.spec.ts @@ -69,7 +69,7 @@ describe('Auth Utilities', () => { // const type = 'access'; test.each(['access', 'publish', 'unpublish'])('should restrict %s to anonymous users', (type) => { - allow_action(type as ActionsAllowed)( + allow_action(type as ActionsAllowed, { trace: jest.fn()})( createAnonymousRemoteUser(), { ...packageAccess, [type]: ['foo'] @@ -82,7 +82,7 @@ describe('Auth Utilities', () => { }); test.each(['access', 'publish', 'unpublish'])('should allow %s to anonymous users', (type) => { - allow_action(type as ActionsAllowed)( + allow_action(type as ActionsAllowed, { trace: jest.fn()})( createAnonymousRemoteUser(), { ...packageAccess, [type]: [ROLES.$ANONYMOUS] @@ -95,7 +95,7 @@ describe('Auth Utilities', () => { }); test.each(['access', 'publish', 'unpublish'])('should allow %s only if user is anonymous if the logged user has groups', (type) => { - allow_action(type as ActionsAllowed)( + allow_action(type as ActionsAllowed, { trace: jest.fn()})( createRemoteUser('juan', ['maintainer', 'admin']), { ...packageAccess, [type]: [ROLES.$ANONYMOUS] @@ -108,7 +108,7 @@ describe('Auth Utilities', () => { }); test.each(['access', 'publish', 'unpublish'])('should allow %s only if user is anonymous match any other groups', (type) => { - allow_action(type as ActionsAllowed)( + allow_action(type as ActionsAllowed, { trace: jest.fn()})( createRemoteUser('juan', ['maintainer', 'admin']), { ...packageAccess, [type]: ['admin', 'some-other-group', ROLES.$ANONYMOUS] @@ -121,7 +121,7 @@ describe('Auth Utilities', () => { }); test.each(['access', 'publish', 'unpublish'])('should not allow %s anonymous if other groups are defined and does not match', (type) => { - allow_action(type as ActionsAllowed)( + allow_action(type as ActionsAllowed, { trace: jest.fn()})( createRemoteUser('juan', ['maintainer', 'admin']), { ...packageAccess, [type]: ['bla-bla-group', 'some-other-group', ROLES.$ANONYMOUS] @@ -143,14 +143,14 @@ describe('Auth Utilities', () => { describe('getDefaultPlugins', () => { test('authentication should fail by default (default)', () => { - const plugin = getDefaultPlugins(); + const plugin = getDefaultPlugins({ trace: jest.fn()}); plugin.authenticate('foo', 'bar', (error: any) => { expect(error).toEqual(getForbidden(API_ERROR.BAD_USERNAME_PASSWORD)); }); }); test('add user should fail by default (default)', () => { - const plugin: IPluginAuth = getDefaultPlugins(); + const plugin = getDefaultPlugins({ trace: jest.fn()}); // @ts-ignore plugin.adduser('foo', 'bar', (error: any) => { expect(error).toEqual(getForbidden(API_ERROR.BAD_USERNAME_PASSWORD)); diff --git a/packages/verdaccio/debug/bootstrap.js b/packages/verdaccio/debug/bootstrap.js new file mode 100644 index 000000000..8d16cc02a --- /dev/null +++ b/packages/verdaccio/debug/bootstrap.js @@ -0,0 +1,6 @@ +// this file aims to help local debugging with hot transpilation +// it requires BABEL_ENV=registry set as env variable +require('@babel/register')({ + extensions: [".ts"] +}); +require('@verdaccio/cli'); diff --git a/packages/verdaccio/test/functional/index.spec.ts b/packages/verdaccio/test/functional/index.spec.ts index b968c4edb..8ac83f59a 100644 --- a/packages/verdaccio/test/functional/index.spec.ts +++ b/packages/verdaccio/test/functional/index.spec.ts @@ -3,8 +3,6 @@ import { setup } from '@verdaccio/logger'; setup({}); -// import {IServerBridge} from '../types'; - import basic from './basic/basic'; import packageAccess from './package/access'; import packageGzip from './package/gzip'; diff --git a/packages/verdaccio/test/functional/lib/environment.ts b/packages/verdaccio/test/functional/lib/environment.ts index d44e90aa1..e98aaeea5 100644 --- a/packages/verdaccio/test/functional/lib/environment.ts +++ b/packages/verdaccio/test/functional/lib/environment.ts @@ -58,7 +58,7 @@ class FunctionalEnvironment extends NodeEnvironment { const server = mockServer(serverConf.port, { storePath, configPath, - silence: true + silence: false }); const fork = await server.init(binPath); diff --git a/packages/verdaccio/test/functional/store/server1/config-1.yaml b/packages/verdaccio/test/functional/store/server1/config-1.yaml index 1e1bcd9bb..7c1cd5501 100644 --- a/packages/verdaccio/test/functional/store/server1/config-1.yaml +++ b/packages/verdaccio/test/functional/store/server1/config-1.yaml @@ -31,8 +31,7 @@ uplinks: baduplink: url: http://localhost:55666/ -logs: - - { type: stdout, format: pretty, level: info } +logs: { type: stdout, format: pretty, level: info } packages: '@test/*': diff --git a/packages/verdaccio/test/functional/store/server2/config-2.yaml b/packages/verdaccio/test/functional/store/server2/config-2.yaml index 82c80e46f..d17ba9151 100644 --- a/packages/verdaccio/test/functional/store/server2/config-2.yaml +++ b/packages/verdaccio/test/functional/store/server2/config-2.yaml @@ -32,8 +32,8 @@ auth: name: authtest password: blahblah-password -logs: { type: stdout, format: pretty, level: trace } - +logs: { type: stdout, format: pretty, level: trace +} packages: '@test/*': access: $all diff --git a/packages/verdaccio/test/unit/partials/config/yaml/api.spec/web-config.yaml b/packages/verdaccio/test/unit/partials/config/yaml/api.spec/web-config.yaml index fa63f82d5..95b095aed 100644 --- a/packages/verdaccio/test/unit/partials/config/yaml/api.spec/web-config.yaml +++ b/packages/verdaccio/test/unit/partials/config/yaml/api.spec/web-config.yaml @@ -48,5 +48,4 @@ packages: access: $all publish: $all -logs: - - { type: stdout, format: pretty, level: warns } +logs: { type: stdout, format: pretty, level: warns } diff --git a/yarn.lock b/yarn.lock index f83ed9a17..d3ac10c63 100644 Binary files a/yarn.lock and b/yarn.lock differ