feat: migrate from buyan to pinojs (#1760)

* feat: migrate from buyan to pinojs

* chore: fix lint

* chore: release utils from import

* chore: fix test

* chore: add missing dep

* chore: add dependency

* chore: add prettifier module

* chore: add pretty stamp option

* chore: fix package name location

* chore: crash on try use rotating file type

* chore: remove arg

.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

.gitignore

@@ -1,4 +1,4 @@
-npm-debug.log
+*.log*
 verdaccio-*.tgz
 .DS_Store
 build/

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"

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",

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"

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 {

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';
 

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);
 	}
 }

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}`;

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"
 }

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

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

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;

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');

packages/logger-prettify/.babelrc

@@ -0,0 +1,3 @@
+{
+  "presets": [["@verdaccio"]]
+}

packages/logger-prettify/.eslintrc

@@ -0,0 +1,8 @@
+{
+  "extends": [
+    "@verdaccio"
+  ],
+  "rules": {
+    "guard-for-in": 0
+  }
+}

packages/logger-prettify/jest.config.js

@@ -0,0 +1,4 @@
+const config = require('../../jest/config');
+
+module.exports = Object.assign({}, config, {});
+

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"
+}

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;
+}

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;
+	};
+};

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,
+    },
 };

packages/logger-prettify/src/types.ts

@@ -0,0 +1,5 @@
+import {PrettyOptions} from "pino";
+
+export interface  PrettyOptionsExtended extends PrettyOptions {
+	prettyStamp: boolean;
+}

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}`;
+}

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"`;

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
+"
+`;

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: '<Classified>',
+						'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();
+		});
+	});
+});

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();
+	});
+});

packages/logger-prettify/tsconfig.json

@@ -0,0 +1,10 @@
+{
+  "extends": "../../tsconfig",
+  "compilerOptions": {
+    "rootDir": "./src",
+    "outDir": "./build",
+    "allowSyntheticDefaultImports": true
+  },
+  "include": ["src/**/*"],
+  "exclude": ["src/**/*.test.ts"]
+}

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,
+});
 

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"
 }

packages/logger/src/format/json.ts

@@ -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`;
-}

packages/logger/src/format/pretty-timestamped.ts

@@ -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`;
-}

packages/logger/src/format/pretty.ts

@@ -1,5 +0,0 @@
-import { printMessage } from '../formatter';
-
-export function pretty(obj, hasColors): string {
-  return `${printMessage(obj.level, obj.msg, obj, hasColors)}\n`;
-}

packages/logger/src/formatter.ts

@@ -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);
-  });
-}

packages/logger/src/index.ts

@@ -1 +1,2 @@
-export { setup, logger } from './logger';
+export { setup, createLogger, logger } from './logger';
+

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);
+	}));
+}

packages/logger/src/utils.ts

@@ -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;
-}

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);
+	});
+});

packages/logger/test/parser.spec.ts

@@ -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`);
-      });
-    });
-  });
-});

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}

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}`;

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));
     }

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(
           {

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;

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<Config> {
+export function getDefaultPlugins(logger: any): IPluginAuth<Config> {
   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<Config> {
 
     // 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),
   };
 }
 

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<Config> = getDefaultPlugins();
+			const plugin = getDefaultPlugins({ trace: jest.fn()});
 			// @ts-ignore
 			plugin.adduser('foo', 'bar', (error: any) => {
 				expect(error).toEqual(getForbidden(API_ERROR.BAD_USERNAME_PASSWORD));

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');

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';

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);

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/*':

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

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 }