refactor middleware dependencies (#3588)

* refactor middleware dependencies

* improve wrap

* chore: fix local

* chore: fix test

* changeset

.changeset/eight-bottles-own.md

@@ -0,0 +1,8 @@
+---
+'@verdaccio/middleware': patch
+'@verdaccio/server': patch
+'@verdaccio/test-helper': patch
+'@verdaccio/local-publish': patch
+---
+
+fix: extract logger from middleware

package.json

@@ -157,7 +157,8 @@
     "crowdin:sync": "pnpm crowdin:upload && pnpm crowdin:download --verbose",
     "postinstall": "husky install",
     "local:registry": "pnpm start --filter ...@verdaccio/local-publish",
-    "local:publish": "cross-env npm_config_registry=http://localhost:4873 pnpm ci:publish",
+    "local:snapshots": "changeset version --snapshot",
+    "local:publish": "cross-env npm_config_registry=http://localhost:4873 pnpm ci:publish -- --no-git-tag",
     "local:publish:release": "concurrently \"pnpm local:registry\" \"pnpm local:publish\""
   },
   "pnpm": {

packages/middleware/jest.config.js

@@ -4,7 +4,7 @@ module.exports = Object.assign({}, config, {
   coverageThreshold: {
     global: {
       lines: 67,
-      functions: 80,
+      functions: 75,
       branches: 56,
       statements: 67,
     },

packages/middleware/package.json

@@ -26,8 +26,7 @@
     "verdaccio"
   ],
   "engines": {
-    "node": ">=14",
+    "node": ">=12"
-    "npm": ">=6"
   },
   "scripts": {
     "clean": "rimraf ./build",
@@ -40,7 +39,6 @@
   },
   "dependencies": {
     "@verdaccio/core": "workspace:6.0.0-6-next.56",
-    "@verdaccio/logger": "workspace:6.0.0-6-next.24",
     "@verdaccio/utils": "workspace:6.0.0-6-next.24",
     "debug": "4.3.4",
     "lodash": "4.17.21",
@@ -51,6 +49,7 @@
     "url": "https://opencollective.com/verdaccio"
   },
   "devDependencies": {
+    "@verdaccio/logger": "workspace:6.0.0-6-next.24",
     "body-parser": "1.20.1",
     "supertest": "6.3.3"
   }

packages/middleware/src/middlewares/error.ts

@@ -3,76 +3,77 @@ import { HttpError } from 'http-errors';
 import _ from 'lodash';
 
 import { API_ERROR, HTTP_STATUS, VerdaccioError } from '@verdaccio/core';
-import { logger } from '@verdaccio/logger';
 
 import { $NextFunctionVer, $RequestExtend, $ResponseExtend } from '../types';
 
 const debug = buildDebug('verdaccio:middleware:error');
 
-export function handleError(
+export const handleError = (logger) =>
-  err: HttpError,
+  function handleError(
-  req: $RequestExtend,
+    err: HttpError,
-  res: $ResponseExtend,
+    req: $RequestExtend,
-  next: $NextFunctionVer
+    res: $ResponseExtend,
-) {
+    next: $NextFunctionVer
-  debug('error handler init');
+  ) {
-  if (_.isError(err)) {
+    debug('error handler init');
-    debug('is native error');
+    if (_.isError(err)) {
-    if (err.code === 'ECONNABORT' && res.statusCode === HTTP_STATUS.NOT_MODIFIED) {
+      debug('is native error');
-      return next();
+      if (err.code === 'ECONNABORT' && res.statusCode === HTTP_STATUS.NOT_MODIFIED) {
+        return next();
+      }
+      if (_.isFunction(res.locals.report_error) === false) {
+        debug('is locals error report ref');
+        // in case of very early error this middleware may not be loaded before error is generated
+        // fixing that
+        errorReportingMiddleware(logger)(req, res, _.noop);
+      }
+      debug('set locals error report ref');
+      res.locals.report_error(err);
+    } else {
+      // Fall to Middleware.final
+      debug('no error to report, jump next layer');
+      return next(err);
     }
-    if (_.isFunction(res.locals.report_error) === false) {
+  };
-      debug('is locals error report ref');
-      // in case of very early error this middleware may not be loaded before error is generated
-      // fixing that
-      errorReportingMiddleware(req, res, _.noop);
-    }
-    debug('set locals error report ref');
-    res.locals.report_error(err);
-  } else {
-    // Fall to Middleware.final
-    debug('no error to report, jump next layer');
-    return next(err);
-  }
-}
 
 // Middleware
-export function errorReportingMiddleware(
+export const errorReportingMiddleware = (logger) =>
-  req: $RequestExtend,
+  function errorReportingMiddleware(
-  res: $ResponseExtend,
+    req: $RequestExtend,
-  next: $NextFunctionVer
+    res: $ResponseExtend,
-): void {
+    next: $NextFunctionVer
-  debug('error report middleware');
+  ): void {
-  res.locals.report_error =
+    debug('error report middleware');
-    res.locals.report_error ||
+    res.locals.report_error =
-    function (err: VerdaccioError): void {
+      res.locals.report_error ||
-      if (err.status && err.status >= HTTP_STATUS.BAD_REQUEST && err.status < 600) {
+      function (err: VerdaccioError): void {
-        debug('is error > 409 %o', err?.status);
+        if (err.status && err.status >= HTTP_STATUS.BAD_REQUEST && err.status < 600) {
-        if (_.isNil(res.headersSent) === false) {
+          debug('is error > 409 %o', err?.status);
-          debug('send status %o', err?.status);
+          if (_.isNil(res.headersSent) === false) {
-          res.status(err.status);
+            debug('send status %o', err?.status);
-          debug('next layer %o', err?.message);
+            res.status(err.status);
-          next({ error: err.message || API_ERROR.UNKNOWN_ERROR });
+            debug('next layer %o', err?.message);
-        }
+            next({ error: err.message || API_ERROR.UNKNOWN_ERROR });
-      } else {
+          }
-        debug('is error < 409 %o', err?.status);
-        logger.error({ err: err }, 'unexpected error: @{!err.message}\n@{err.stack}');
-        if (!res.status || !res.send) {
-          // TODO: decide which debug keep
-          logger.error('this is an error in express.js, please report this');
-          debug('this is an error in express.js, please report this, destroy response %o', err);
-          res.destroy();
-        } else if (!res.headersSent) {
-          debug('report internal error %o', err);
-          res.status(HTTP_STATUS.INTERNAL_ERROR);
-          next({ error: API_ERROR.INTERNAL_SERVER_ERROR });
         } else {
-          // socket should be already closed
+          debug('is error < 409 %o', err?.status);
-          debug('this should not happen, otherwise report %o', err);
+          logger.error({ err: err }, 'unexpected error: @{!err.message}\n@{err.stack}');
+          if (!res.status || !res.send) {
+            // TODO: decide which debug keep
+            logger.error('this is an error in express.js, please report this');
+            debug('this is an error in express.js, please report this, destroy response %o', err);
+            res.destroy();
+          } else if (!res.headersSent) {
+            debug('report internal error %o', err);
+            res.status(HTTP_STATUS.INTERNAL_ERROR);
+            next({ error: API_ERROR.INTERNAL_SERVER_ERROR });
+          } else {
+            // socket should be already closed
+            debug('this should not happen, otherwise report %o', err);
+          }
         }
-      }
+      };
-    };
 
-  debug('error report middleware next()');
+    debug('error report middleware next()');
-  next();
+    next();
-}
+  };

packages/middleware/src/middlewares/log.ts

@@ -1,7 +1,5 @@
 import _ from 'lodash';
 
-import { logger } from '@verdaccio/logger';
-
 import { $NextFunctionVer, $RequestExtend, $ResponseExtend } from '../types';
 
 // FIXME: deprecated, moved to @verdaccio/dev-commons
@@ -10,94 +8,96 @@ export const LOG_STATUS_MESSAGE =
 export const LOG_VERDACCIO_ERROR = `${LOG_STATUS_MESSAGE}, error: @{!error}`;
 export const LOG_VERDACCIO_BYTES = `${LOG_STATUS_MESSAGE}, bytes: @{bytes.in}/@{bytes.out}`;
 
-export function log(req: $RequestExtend, res: $ResponseExtend, next: $NextFunctionVer): void {
+export const log = (logger) => {
-  // logger
+  return function log(req: $RequestExtend, res: $ResponseExtend, next: $NextFunctionVer): void {
-  req.log = logger.child({ sub: 'in' });
+    // logger
+    req.log = logger.child({ sub: 'in' });
 
-  const _auth = req.headers.authorization;
+    const _auth = req.headers.authorization;
-  if (_.isNil(_auth) === false) {
+    if (_.isNil(_auth) === false) {
-    req.headers.authorization = '<Classified>';
+      req.headers.authorization = '<Classified>';
-  }
+    }
 
-  const _cookie = req.get('cookie');
+    const _cookie = req.get('cookie');
-  if (_.isNil(_cookie) === false) {
+    if (_.isNil(_cookie) === false) {
-    req.headers.cookie = '<Classified>';
+      req.headers.cookie = '<Classified>';
-  }
-
-  req.url = req.originalUrl;
-  req.log.info({ req: req, ip: req.ip }, "@{ip} requested '@{req.method} @{req.url}'");
-  req.originalUrl = req.url;
-
-  if (_.isNil(_auth) === false) {
-    req.headers.authorization = _auth;
-  }
-
-  if (_.isNil(_cookie) === false) {
-    req.headers.cookie = _cookie;
-  }
-
-  let bytesin = 0;
-  req.on('data', function (chunk): void {
-    bytesin += chunk.length;
-  });
-
-  let bytesout = 0;
-  const _write = res.write;
-  // FIXME: res.write should return boolean
-  // @ts-ignore
-  res.write = function (buf): boolean {
-    bytesout += buf.length;
-    /* eslint prefer-rest-params: "off" */
-    // @ts-ignore
-    _write.apply(res, arguments);
-  };
-
-  const log = function (): void {
-    const forwardedFor = req.get('x-forwarded-for');
-    const remoteAddress = req.connection.remoteAddress;
-    const remoteIP = forwardedFor ? `${forwardedFor} via ${remoteAddress}` : remoteAddress;
-    let message;
-    if (res.locals._verdaccio_error) {
-      message = LOG_VERDACCIO_ERROR;
-    } else {
-      message = LOG_VERDACCIO_BYTES;
     }
 
     req.url = req.originalUrl;
-    req.log.http(
+    req.log.info({ req: req, ip: req.ip }, "@{ip} requested '@{req.method} @{req.url}'");
-      {
-        request: {
-          method: req.method,
-          url: req.url,
-        },
-        user: req.remote_user?.name || null,
-        remoteIP,
-        status: res.statusCode,
-        error: res.locals._verdaccio_error,
-        bytes: {
-          in: bytesin,
-          out: bytesout,
-        },
-      },
-      message
-    );
     req.originalUrl = req.url;
-  };
 
-  req.on('close', function (): void {
+    if (_.isNil(_auth) === false) {
-    log();
+      req.headers.authorization = _auth;
-  });
-
-  const _end = res.end;
-  // @ts-ignore
-  res.end = function (buf): void {
-    if (buf) {
-      bytesout += buf.length;
     }
-    /* eslint prefer-rest-params: "off" */
+
+    if (_.isNil(_cookie) === false) {
+      req.headers.cookie = _cookie;
+    }
+
+    let bytesin = 0;
+    req.on('data', function (chunk): void {
+      bytesin += chunk.length;
+    });
+
+    let bytesout = 0;
+    const _write = res.write;
+    // FIXME: res.write should return boolean
     // @ts-ignore
-    _end.apply(res, arguments);
+    res.write = function (buf): boolean {
-    log();
+      bytesout += buf.length;
+      /* eslint prefer-rest-params: "off" */
+      // @ts-ignore
+      _write.apply(res, arguments);
+    };
+
+    const log = function (): void {
+      const forwardedFor = req.get('x-forwarded-for');
+      const remoteAddress = req.connection.remoteAddress;
+      const remoteIP = forwardedFor ? `${forwardedFor} via ${remoteAddress}` : remoteAddress;
+      let message;
+      if (res.locals._verdaccio_error) {
+        message = LOG_VERDACCIO_ERROR;
+      } else {
+        message = LOG_VERDACCIO_BYTES;
+      }
+
+      req.url = req.originalUrl;
+      req.log.http(
+        {
+          request: {
+            method: req.method,
+            url: req.url,
+          },
+          user: req.remote_user?.name || null,
+          remoteIP,
+          status: res.statusCode,
+          error: res.locals._verdaccio_error,
+          bytes: {
+            in: bytesin,
+            out: bytesout,
+          },
+        },
+        message
+      );
+      req.originalUrl = req.url;
+    };
+
+    req.on('close', function (): void {
+      log();
+    });
+
+    const _end = res.end;
+    // @ts-ignore
+    res.end = function (buf): void {
+      if (buf) {
+        bytesout += buf.length;
+      }
+      /* eslint prefer-rest-params: "off" */
+      // @ts-ignore
+      _end.apply(res, arguments);
+      log();
+    };
+    next();
   };
-  next();
+};
-}

packages/middleware/test/log.spec.ts

@@ -2,7 +2,7 @@ import path from 'path';
 import request from 'supertest';
 
 import { HTTP_STATUS } from '@verdaccio/core';
-import { setup } from '@verdaccio/logger';
+import { logger, setup } from '@verdaccio/logger';
 
 import { log } from '../src';
 import { getApp } from './helper';
@@ -17,7 +17,7 @@ setup({
 test('should log request', async () => {
   const app = getApp([]);
   // @ts-ignore
-  app.use(log);
+  app.use(log(logger));
   // @ts-ignore
   app.get('/:package', (req, res) => {
     res.status(HTTP_STATUS.OK).json({});

packages/server/express/src/server.ts

@@ -36,9 +36,11 @@ const defineAPI = async function (config: IConfig, storage: Storage): Promise<an
   app.use(cors());
   app.use(limiter);
 
+  const errorReportingMiddlewareWrap = errorReportingMiddleware(logger);
+
   // Router setup
-  app.use(log);
+  app.use(log(logger));
-  app.use(errorReportingMiddleware);
+  app.use(errorReportingMiddlewareWrap);
   app.use(function (req: $RequestExtend, res: $ResponseExtend, next: $NextFunctionVer): void {
     res.setHeader('x-powered-by', getUserAgent(config.user_agent));
     next();
@@ -111,7 +113,7 @@ const defineAPI = async function (config: IConfig, storage: Storage): Promise<an
       if (_.isFunction(res.locals.report_error) === false) {
         // in case of very early error this middleware may not be loaded before error is generated
         // fixing that
-        errorReportingMiddleware(req, res, _.noop);
+        errorReportingMiddlewareWrap(req, res, _.noop);
       }
       res.locals.report_error(err);
     } else {

packages/tools/helpers/package.json

@@ -14,6 +14,7 @@
     "@verdaccio/core": "workspace:6.0.0-6-next.56",
     "@verdaccio/config": "workspace:6.0.0-6-next.56",
     "@verdaccio/middleware": "workspace:6.0.0-6-next.35",
+    "@verdaccio/logger": "workspace:6.0.0-6-next.24",
     "@verdaccio/utils": "workspace:6.0.0-6-next.24",
     "body-parser": "1.20.1",
     "express": "4.18.2",

packages/tools/helpers/src/initializeServer.ts

@@ -7,6 +7,7 @@ import path from 'path';
 import { Auth } from '@verdaccio/auth';
 import { Config } from '@verdaccio/config';
 import { errorUtils } from '@verdaccio/core';
+import { logger } from '@verdaccio/logger';
 import { errorReportingMiddleware, final, handleError } from '@verdaccio/middleware';
 import { generateRandomHexString } from '@verdaccio/utils';
 
@@ -31,7 +32,7 @@ export async function initializeServer(
   // TODO: this might not be need it, used in apiEndpoints
   app.use(bodyParser.json({ strict: false, limit: '10mb' }));
   // @ts-ignore
-  app.use(errorReportingMiddleware);
+  app.use(errorReportingMiddleware(logger));
   for (let route of routesMiddleware) {
     if (route.async) {
       const middleware = await route.routes(config, auth, storage);
@@ -47,7 +48,7 @@ export async function initializeServer(
   });
 
   // @ts-ignore
-  app.use(handleError);
+  app.use(handleError(logger));
   // @ts-ignore
   app.use(final);
 

packages/tools/local-publish/src/index.ts

@@ -12,7 +12,7 @@ fileUtils
       logs: { level: 'info', type: 'stdout', format: 'pretty' },
       uplinks: {},
       packages: {},
-      self_path: folderPath,
+      configPath: folderPath,
     })
       .addUplink('npmjs', { url: 'https://registry.npmjs.org' })
       .addPackageAccess('@verdaccio/*', {