Process hanging when upgrading esbuild to 0.15.13+

[pcattori]

The Remix compiler uses esbuild v0.15.12. When we try to upgrade to 0.15.13 or newer, our CLI tests that call the compiler hang indefinitely. This may be related to the deadlock fixes in 0.15.13.

Specifically, this race condition occurs only when we run the CLI (and consequently, esbuild) within a spawned process. It hangs everytime I run our compiler in this way. I tried to reproduce with a simpler setup, but can't get the race condition to appear reliably.

Even though I see that my console.logs after await esbuild.build(...) are outputting to the debug console, the node process hangs on process.exit()

If I throw an error right before my process.exit() call in the CLI, I see Go deadlock errors:

fatal error: all goroutines are asleep - deadlock!

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0x140000a8000?)
        runtime/sema.go:62 +0x28
sync.(*WaitGroup).Wait(0x140000aa2d8)
        sync/waitgroup.go:139 +0x80
main.runService.func2()
        github.com/evanw/esbuild/cmd/esbuild/service.go:150 +0xf8
main.runService(0x1)
        github.com/evanw/esbuild/cmd/esbuild/service.go:204 +0x448
main.main()
        github.com/evanw/esbuild/cmd/esbuild/main.go:231 +0x1b0

goroutine 18 [chan receive]:
main.runService.func1()
        github.com/evanw/esbuild/cmd/esbuild/service.go:111 +0x4c
created by main.runService
        github.com/evanw/esbuild/cmd/esbuild/service.go:109 +0x154

goroutine 19 [chan receive]:
main.(*serviceType).sendRequest(0x140000aa2c0, {0x104d6bc20, 0x14000cfee10})
        github.com/evanw/esbuild/cmd/esbuild/service.go:252 +0x210
main.runService.func3()
        github.com/evanw/esbuild/cmd/esbuild/service.go:161 +0x38
created by main.runService
        github.com/evanw/esbuild/cmd/esbuild/service.go:158 +0x2b4

I also see an esbuild process lingering on my system:

❯ ps                           
  PID TTY           TIME CMD
90793 ttys000    0:12.23 -zsh
 4256 ttys001    0:04.76 -zsh
12022 ttys003    0:01.29 /bin/zsh -il
14562 ttys003    0:00.23 node script.js ../my-remix-app
14567 ttys003    0:00.17 /Users/pedrocattori/remix-run/remix/node_modules/esbuild-darwin-arm64/bin/esbuild --service=0.15.13 --ping

Manually killing the esbuild process lets the node process resume and finish.
Note that esbuild is already done building by the time it hangs, so when esbuild is killed it has already written the output to disk.

Reproduce

1 Setup dummy Remix project

npx create-remix@latest
# choose the default `./my-remix-app` name
# choose "Just the basics"
# choose the default "Typescript"
# choose "y" to run `npm install`

2 Setup Remix repo

git clone https://github.com/remix-run/remix
cd remix
yarn
cd packages/remix-dev
yarn add esbuild@0.15.13
cd -
yarn build --tsc

3 Run script

Then create a script.js with the following contents:

let path = require("node:path")
let execa = require("execa");

let { readConfig } = require("./build/node_modules/@remix-run/dev/dist/config")
let { build } = require("./build/node_modules/@remix-run/dev/dist/compiler/build")

let main1 = async () => {
  let args = process.argv.slice(2);
  if (args.length > 1) throw Error("wrong usage");
  let projectDir =
    args[0] === undefined ? process.cwd() : path.resolve(args[0]);
  console.log(projectDir);
  let config = await readConfig(projectDir);

  console.log("Config:");
  console.log(config);

  console.log("Building...");
  await build(config);
  console.log("Done");
  process.exit();
};

let main2 = async () => {
  let args = process.argv.slice(2);
  if (args.length > 1) throw Error("wrong usage");
  let projectDir =
    args[0] === undefined ? process.cwd() : path.resolve(args[0]);
  console.log(projectDir);

  // console.log("Config:");
  // console.log(config);

  let cliPath = path.resolve(
    __dirname,
    "build/node_modules/@remix-run/dev/dist/cli.js"
  );
  let { stdout } = await execa("node", [cliPath, "build"], {
    cwd: projectDir,
  });
  // console.log(stdout);
  process.exit();
};

// main1();
main2();

Then run the script: node ./script ../my-remix-app
Running with main1 works great, but running main2 hangs.

[pcattori]

If it helps, I'm happy to screenshare my reproduction since its a bit involved to go through all the steps.

[evanw]

I'm unable to reproduce this given these instructions. When I try it, I get this error message when running main1:

The path "@prisma/client" is imported in ../my-remix-app/app/db.server.ts but "@prisma/client" was not found in your node_modules. Did you forget to install it?
The path "bcryptjs" is imported in ../my-remix-app/app/models/user.server.ts but "bcryptjs" was not found in your node_modules. Did you forget to install it?

✘ [ERROR] Could not resolve "./styles/tailwind.css"

    ../my-remix-app/app/root.tsx:12:34:
      12 │ import tailwindStylesheetUrl from "./styles/tailwind.css";
         ╵                                   ~~~~~~~~~~~~~~~~~~~~~~~

Running main2 does indeed hang (with no output). But when I looked into it, the internal stderr stream contains the same error message. The reason for the hang appears to be because the execa library you're using doesn't ever resolve the promise for the stderr stream. I'm not sure why that's the case, but that's where I stopped debugging. Perhaps a screen recording of your reproduction would be helpful.

[pcattori]

Oops forgot to include the "generate styles" step under the dummy Remix project setup. Should be npm run build:css within the project created by npx create-remix@latest. I edited the repro instructions to add that in.

Update: I was able to reproduce with a simple Remix app, so updated the repro instructions to use the "Just the basics" option when creating the dummy app.

---

Note that the problem occurs even if you swap out execa's child process spawning to cross-spawn or the built-in child_process spawning functions. So not something that only happens for execa.

I'll work on getting a screen recording as well.

[pcattori]

Another thing I've noticed is that if I add:

  let open = {
    handles: process._getActiveHandles(),
    requests: process._getActiveRequests(),
  }

just before the process.exit call for the CLI, and add a break point on that process.exit call, I see a ChildProcess reported as an active handle with a PID matching the hanging esbuild process:

[dnalborczyk]

I can confirm. I'm maintaining a plugin for the serverless framework and we have some scenario tests with 3rd party frameworks, one of them is an esbuild plugin for the the serverless framework. when we bump the dependencies to 0.15.13+ the test halts. I have not looked into the issue as the culprit could also be the plugin wrapping esbuild.

scenario tests for serverless-esbuild: https://github.com/dherault/serverless-offline/tree/master/tests/scenario/serverless-plugins/serverless-esbuild

I try to find some time looking a bit deeper into the issue if no one beats me to it.

[pcattori]

Here's a screen recording of the repro: https://www.youtube.com/watch?v=jNr3HvZW18Y

Note that if I set breakpoints and wait a bit before clicking "continue" at the breakpoint, then esbuild doesn't hang. But if I don't set breakpoints or click "continue" quickly, then esbuild does hang. So seems like a race condition.

[evanw]

I still can't reproduce the deadlock, but I can reproduce the hang. Here's a reduced test case:

require('fs').writeFileSync(__dirname + '/foo.js', `
  require('esbuild').build({
    incremental: true, // This must be set to true
  }).then(() => {
    console.log('success')
    process.exit(0)
  })
`)

require('child_process').execFileSync('node', [__dirname + '/foo.js'], {
  stdio: [
    'inherit',
    'inherit',
    'pipe', // This must not be 'inherit'
  ],
})

This exits with esbuild@0.15.12 but hangs with esbuild@0.15.13.

[evanw]

The problem is that the fix for #2485 accidentally disabled the keep-alive ping of the parent process. So when the parent process exits without explicitly terminating esbuild, esbuild now doesn't detect that it's no longer needed and stays running. I'm thinking about what to do about this.

[pcattori]

Yea I've been imprecise and using "deadlock" and "hang" interchangeably here. The hanging is reproducible, but I've only seen the deadlock sporadically as I try experimenting with my setup.

Thanks for looking into this! 🙏