Skip to main content
overcache

Debug the debug module

context

最近发现执行 npx hyext init 的时候会遇到报错(但是用 hyext init 就不会):

(node:23815) UnhandledPromiseRejectionWarning: Error: Cannot find module 'debug'
Require stack:
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/core/lib/config/files/configuration.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/core/lib/config/files/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/core/lib/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/helper-create-class-features-plugin/lib/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/plugin-proposal-class-properties/lib/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@hyext/compile/src/features/stylesheet.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@hyext/compile/src/features/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@hyext/compile/src/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@hyext/builder-beyond/dist/index.js
- /private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@hyext/cli/bin/hyext-init.js
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:831:15)
    at Function.Module._load (internal/modules/cjs/loader.js:687:27)
    at Module.require (internal/modules/cjs/loader.js:903:19)
    at require (internal/modules/cjs/helpers.js:74:18)
    at _debug (/private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/core/lib/config/files/configuration.js:14:39)
    at Object.<anonymous> (/private/var/folders/fz/k7hs8vvn0hj3__tbd8h8j4gr0000gn/T/dz-sdk-demo/node_modules/@babel/core/lib/config/files/configuration.js:71:19)
    at Module._compile (internal/modules/cjs/loader.js:1015:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1035:10)
    at Module.load (internal/modules/cjs/loader.js:879:32)
    at Function.Module._load (internal/modules/cjs/loader.js:724:14)
(node:23815) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)
(node:23815) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

nodejs 抱怨找不到 debug 这个包, 这个包是 babel 的依赖. 触发报错的源码大概长这样:

async function init() {
	// 使用 spawn 调用 npm install 安装依赖
	await installPkg('@hyext/builder-beyond')
	const builder = require('@hyext/builder-beyond') // error
	...
}

过程

0. 临时解决

把 debug 声明为 @hyext/cli 的依赖, 就没报错了, 发了新版本临时修复.

1. settimeout

怀疑是安装完依赖后, 文件还没有完全写入到磁盘, 所以 require 失败了. 所以在 require 前进行了等待, 发现没用.

而且 require 前用 fs.readdirSync 把 node_modules 打印出来, 也能看到 debug 文件夹存在

2. require.cache

继而怀疑是 require 缓存了不正确的 debug 路径, 导致找不到. 所以 require 前用 Object.keys(require.cahce).forEach(key => delete require.cache[key]) 把缓存清了, 还是没用.

把 require.cache 打印出来, 没发现有 debug 这个模块的记录

3. 复现

百思不得其解, 于是搞了脚本尝试复现这个场景, 在同个进程里 install 然后 require, 当然没能复现报错(不然全局的 hyext init 也会报错)

4. DDD

只能用 delete driven development 删代码了, 删完后定位到:

const { apiFactory } = require('@hyext/config')

@hyext/config 也没干啥东西, 怎么就会导致报错呢. 看了依赖用到了 axios , 想起之前在项目的 package-lock.json 搜索 debug 时瞄到好像 axios 也依赖 debug 这个包:

    "axios": {
      "version": "0.19.2",
      "resolved": "https://nexus.huya.com/repository/npm-public/axios/-/axios-0.19.2.tgz",
      "integrity": "sha1-PqNsXYgY0NX4qKl6bTa4bNwAyyc=",
      "dev": true,
      "requires": {
        "follow-redirects": "1.5.10"
      },
      "dependencies": {
        "debug": {
          "version": "3.1.0",
          "resolved": "https://nexus.huya.com/repository/npm-public/debug/-/debug-3.1.0.tgz",
          "integrity": "sha1-W7WgZyYotkFJVmuhaBnmFRjGcmE=",
          "dev": true,
          "requires": {
            "ms": "2.0.0"
          }
        },
        "follow-redirects": {
          "version": "1.5.10",
          "resolved": "https://nexus.huya.com/repository/npm-public/follow-redirects/-/follow-redirects-1.5.10.tgz",
          "integrity": "sha1-e3qfmuov3/NnhqlP9kPtB/T/Xio=",
          "dev": true,
          "requires": {
            "debug": "=3.1.0"
          }
        },
        "ms": {
          "version": "2.0.0",
          "resolved": "https://nexus.huya.com/repository/npm-public/ms/-/ms-2.0.0.tgz",
          "integrity": "sha1-VgiurfwAvmwpAd9fmGF4jeDVl8g=",
          "dev": true
        }
      }
    },

有个 follow-redirects 的库也依赖了 debug, 去看了他代码:

// node_moduels/follow-redirects/debug.js

var debug;
try {
  /* eslint global-require: off */
  debug = require("debug")("follow-redirects");
}
catch (error) {
  debug = function () { /* */ };
}
module.exports = debug;

再看他的 package.json, 没看到声明 debug 为 dep/peerDep, 他的 1.13.1 版本倒是声明了一个字段:

...
"peerDependenciesMeta": {
    "debug": {
      "optional": true
    }
  },
...

意思就是这个包是可选的依赖, 有就最好, 没有的话 npm 也不会 warning.

那就大概知道是怎么回事了:

在 follow-redirects 这个包被引入的时候, 他就尝试去require debug 这个包, 但是这个时候该包还不存在, 所以 nodejs 缓存了这次结果(不过这个缓存没有在 require.cache 里暴露出来, 所以你清不掉). 后来虽然安装了这个包, 但是再次 require 时 nodejs 用了缓存的结果, 认定没有这个包.

证实

用关键词 “nodejs cache MODULE_NOT_FOUND” 搜到一个 issue:

https://github.com/nodejs/node/issues/26926

证实了 nodejs 确实缓存了 MODULE_NOT_FOUND. 随后在 v15.5.1 中修复了这个问题

https://github.com/nodejs/node/commit/8a6dcd040f35b023f0cc0208c4bc553fcc7e6a4d

解决方案

以下任何方法均可

  1. @hyext/cli 引入 debug 依赖
  2. 给 follow-redirects 提 pr, 不要用 require + try catch 来判断一个包存不存在, 改成 npm ls pkgName
  3. 升级 nodejs 到 15.5.1 之后
  4. 把 require('builder-name') 然后执行 builder.init 的逻辑放到 fork 里执行, fork 会重新打开一个 v8 的实例, 不共用缓存.