Nox process manager exits early with "yarn watch" actions

[robcole]

Realized after doing some digging in the code that Nox was its own shard, and not embedded in lucky_cli.

luckyframework/lucky_cli#752

@matthewmcgarvey LMK if there's anything else I can do to help debug this.

[robcole]

From what I can tell, it looks like the wayProcess#wait is being used may be the trigger: the second 'done' seems to indicate that Process#wait detected it as something that should be exited and have all pipes closed.

# nox output
js_assets  | Starting with pid of 10032
css_assets | Starting with pid of 10033
js_assets    | Done in 0.34s.
js_assets    | Done
css_assets   | Done in 0.58s.
css_assets   | Done

# overmind output
css_assets | Started with pid 9971...
js_assets  | Started with pid 9970...
js_assets  | [watch] build finished, watching for changes...
css_assets |
css_assets | Rebuilding...
css_assets | Done in 142ms.

https://github.com/matthewmcgarvey/nox/blob/main/src/nox/process.cr#L18

[robcole]

Easiest repro is to start with one of the repos I listed, but reduce your Procfile.dev to the following entries:

js_assets: yarn dev:js
css_assets: yarn dev:css

From there, you can see that lucky dev will exit early, and overmind s will continue running and trapping messages.

[robcole]

Looks like this is an issue with Process#wait's implementation in Crystal.

process = Process.new(command: "yarn dev:js", shell: true)
pp process =>

#<Process:0x10f2f4f50
 @channel=nil,
 @error=nil,
 @input=nil,
 @output=nil,
 @process_info=
  Crystal::System::Process(@channel=#<Channel(Int32):0x10f2f7c00>, @pid=11570),
 @wait_count=0>
 
process.wait => exits immediately, no evidence of program running

process2 = Process.new(command: "lucky watch --reload-browser", shell: true)

pp process2 => 

#<Process:0x104880f50
 @channel=nil,
 @error=nil,
 @input=nil,
 @output=nil,
 @process_info=
  Crystal::System::Process(@channel=#<Channel(Int32):0x104883c00>, @pid=11675),
 @wait_count=0>

process2.wait # waits as expected

[robcole]

Finally: Process.exec(command: "yarn dev:js", shell: true) works as expected and continues to run in the background.

[robcole]

Last bit of info for a while -- I think that the issue is that the way yarn scripts work is to run a script that starts other scripts -- here's a running log of what launches when I run both overmind and lucky dev (repeats every second, so you can see the termination output here as well)

while true; do ps auxw | grep "yarn" | grep -v "grep" | grep -v "browser-sync"; sleep 1; done

# overmind

robcole          15776  46.1  0.1 35388184  80752 s006  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:css --watch
robcole          15759  42.8  0.1 35247896  80436 s005  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:js --watch
robcole          15758  21.1  0.1 35377180  80256 s006  S+   11:26AM   0:00.17 node /Users/robcole/.n/bin/yarn dev:css
robcole          15757  14.4  0.1 35341340  79392 s005  S+   11:26AM   0:00.16 node /Users/robcole/.n/bin/yarn dev:js

robcole          15759   0.7  0.1 35247896  80472 s005  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:js --watch
robcole          15776   0.7  0.1 35388184  80756 s006  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:css --watch
robcole          15758   0.3  0.1 35377180  80260 s006  S+   11:26AM   0:00.17 node /Users/robcole/.n/bin/yarn dev:css
robcole          15757   0.2  0.1 35341340  79396 s005  S+   11:26AM   0:00.16 node /Users/robcole/.n/bin/yarn dev:js

robcole          15776   0.0  0.1 35388184  80760 s006  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:css --watch
robcole          15759   0.0  0.1 35247896  80476 s005  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:js --watch
robcole          15758   0.0  0.1 35377180  80260 s006  S+   11:26AM   0:00.17 node /Users/robcole/.n/bin/yarn dev:css
robcole          15757   0.0  0.1 35341340  79396 s005  S+   11:26AM   0:00.16 node /Users/robcole/.n/bin/yarn dev:js

robcole          15776   0.0  0.1 35388184  80760 s006  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:css --watch
robcole          15759   0.0  0.1 35247896  80476 s005  S+   11:26AM   0:00.18 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:js --watch
robcole          15758   0.0  0.1 35377180  80264 s006  S+   11:26AM   0:00.17 node /Users/robcole/.n/bin/yarn dev:css
robcole          15757   0.0  0.1 35341340  79396 s005  S+   11:26AM   0:00.16 node /Users/robcole/.n/bin/yarn dev:js

# nox

robcole          15971  41.1  0.1 35492892  79184 s000  S+   11:27AM   0:00.16 node /Users/robcole/.n/bin/yarn dev:js
robcole          15972  41.0  0.1 35491868  78788 s000  S+   11:27AM   0:00.16 node /Users/robcole/.n/bin/yarn dev:css
robcole          15985   0.9  0.0 33588024     16 s000  S+   11:27AM   0:00.00 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:js --watch
robcole          15984   0.0  0.0 34395040  12628 s000  R+   11:27AM   0:00.02 /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:css --watch

[robcole]

Even if I change my Procfile to what appears to be "running" compared to Overmind (based on ps output), everything still exits; hopefully this helps the next person to try to pick up on this thread.

Overmind works with this Procfile.dev as well, so at this point I'm wondering about node's exit codes themselves. 🤔

system_check: script/system_check && sleep 100000
web: lucky watch --reload-browser
js_assets: /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:js --watch
css_assets: /Users/robcole/.n/bin/node /Users/robcole/.n/bin/yarn build:css --watch
docker: docker-compose up postgres

[robacarp]

Yep, I see that too. It makes sense that --watch tools would fork to make the watch work.

[matthewmcgarvey]

Looking into it now, I'm seeing the js task complete but the css task continue to run and watch for changes.

js_assets  | Starting with pid of 69236
css_assets | Starting with pid of 69237
js_assets  | yarn run v1.22.19
css_assets | yarn run v1.22.19
js_assets  | warning package.json: No license field
css_assets | warning package.json: No license field
js_assets  | $ yarn build:js --watch
css_assets | $ yarn build:css --watch
css_assets | warning package.json: No license field
css_assets | $ tailwindcss --input=src/css/app.css --output=public/css/app.css --watch
js_assets  | warning package.json: No license field
js_assets  | $ esbuild src/js/* --outdir=public/js --bundle --watch
js_assets  | Done in 0.30s.
js_assets  | Done
css_assets |
css_assets | Rebuilding...
css_assets | Done in 99ms.
css_assets |
css_assets | Rebuilding...
css_assets | Done in 69ms.