Ts-node-dev: Cryptic errors when running ts-node-dev

[kachkaev]

Hi @whitecolor!

I was trying to use ts-node-dev develop ts actions in my project, which are just runnable typescript files.

Here's what sometimes happens when I run yarn ts-node-dev --respawn --compile-timeout 30000 --notify=false src/actions/hello.ts:

yarn run v1.3.2
$ /path/to/project/node_modules/.bin/ts-node-dev --respawn --compile-timeout 30000 --notify=false src/actions/hello.ts
Error: Could not require /path/to/project/src/actions/hello.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_actions_hello_ts_4b7034ed73736302bd98ace10b2ead962243eb48412af14fccc6e4c9447a0ee8.js
    at compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:27:13)
    at Module.m._compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:41:36)
    at Module._extensions..js (module.js:671:10)
    at require.extensions.(anonymous function) (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:43:14)
    at Object.nodeDevHook [as .ts] (/path/to/project/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:573:32)
    at tryModuleLoad (module.js:513:12)
    at Function.Module._load (module.js:505:3)
    at Module.require (module.js:604:17)
    at require (internal/module.js:11:18)
[ERROR] 14:11:29 Error: Could not require /path/to/project/src/actions/hello.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_actions_hello_ts_4b7034ed73736302bd98ace10b2ead962243eb48412af14fccc6e4c9447a0ee8.js
[INFO] 14:11:42 Restarting: /path/to/project/src/actions/hello.ts has been modified
Error: Could not require /path/to/project/src/lib/custom-sort-keys.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_lib_custom_sort_keys_ts_85f47a355a422b5df586503ceb1aa07cc0328a953a0c9ebe77023bef5edbbdea.js
    at compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:27:13)
    at Module.m._compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:41:36)
    at Module._extensions..js (module.js:671:10)
    at require.extensions.(anonymous function) (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:43:14)
    at Object.nodeDevHook [as .ts] (/path/to/project/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:573:32)
    at tryModuleLoad (module.js:513:12)
    at Function.Module._load (module.js:505:3)
    at Module.require (module.js:604:17)
    at require (internal/module.js:11:18)
[ERROR] 14:12:12 Error: Could not require /path/to/project/src/lib/custom-sort-keys.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_lib_custom_sort_keys_ts_85f47a355a422b5df586503ceb1aa07cc0328a953a0c9ebe77023bef5edbbdea.js
[INFO] 14:12:16 Restarting: /path/to/project/src/actions/hello.ts has been modified
[INFO] 14:12:46 Restarting: /path/to/project/src/actions/hello.ts has been modified
Error: Could not require /path/to/project/src/lib/extract-legacy-assets-tree.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_lib_extract_legacy_assets_tree_ts_1e7f51aadf447bb3e20188e0469ac27af6675f4ba2b32e9438614f59b57bc1c5.js
    at compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:27:13)
    at Module.m._compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:41:36)
    at Module._extensions..js (module.js:671:10)
    at require.extensions.(anonymous function) (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358259402.js:43:14)
    at Object.nodeDevHook [as .ts] (/path/to/project/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:573:32)
    at tryModuleLoad (module.js:513:12)
    at Function.Module._load (module.js:505:3)
    at Module.require (module.js:604:17)
    at require (internal/module.js:11:18)
Error [ERR_IPC_DISCONNECTED]: IPC channel is already disconnected
    at ChildProcess.target.disconnect (internal/child_process.js:746:26)
    at Pipe.channel.onread (internal/child_process.js:508:14)
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

I don't understand where these are coming from and what is also strange is that I cannot make these errors reproducible for any specific content of my typescript files. For example, the error may show up at first, but then after I comment and uncomment a few lines, it disappears. At the same time, there is a likelihood that the process may completely crash, like in the example above.

Similar errors are shown when I run ts-node-dev without any options:

yarn ts-node-dev src/actions/hello.ts
yarn run v1.3.2
$ /path/to/project/node_modules/.bin/ts-node-dev src/actions/hello.ts
Error: Could not require /path/to/project/src/actions/hello.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_actions_hello_ts_7ac73806ede5e6231c25cb24297c4973531ff760794d55c116c7d946dc8640a4.js
    at compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358523172.js:27:13)
    at Module.m._compile (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358523172.js:41:36)
    at Module._extensions..js (module.js:671:10)
    at require.extensions.(anonymous function) (/private/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/ts-node-dev-hook-1518358523172.js:43:14)
    at Object.nodeDevHook [as .ts] (/path/to/project/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:573:32)
    at tryModuleLoad (module.js:513:12)
    at Function.Module._load (module.js:505:3)
    at Module.require (module.js:604:17)
    at require (internal/module.js:11:18)
[ERROR] 14:15:33 Error: Could not require /path/to/project/src/actions/hello.ts, compiled path:/var/folders/vp/cg66j_sj5_ncxlgvgt7pjn2h0000gn/T/.ts-node/compiled/src_actions_hello_ts_7ac73806ede5e6231c25cb24297c4973531ff760794d55c116c7d946dc8640a4.js

Despite all the errors above, running yarn ts-node src/actions/hello.ts works:

yarn run v1.3.2
$ /path/to/project/node_modules/.bin/ts-node src/actions/hello.ts
ACTION OUTPUT
✨  Done in 0.97s.

What could be causing this? How can I help with debugging given that I'm unable to craft a MWE?

My env:

node 9.5.0
yarn: 1.3.2
ts-node: 4.1.0
ts-node-dev 1.0.0-pre.9
macOS High Sierra

[wclr]

Does ts-node-dev works for you in any other setup? Can you make a repo that reproduces the error?

[kachkaev]

Yeah, ts-node-dev generally works, it just goes into this odd state from time to time for certain files. I'll be happy to share a repo with a reproducible example once I manage to make it stable. So far I could not understand what exactly causes the crash, it feels somewhat random.

It'd be great to hear if anyone else has ever faced that!

[wclr]

Yes, I've met this buggy behaviour before, but I couldn't narrow it down too. ts-node-dev uses hacky solution to await required files to compile, so something wrong should be happening here.

[Koslun]

We observed this error on a Mac OS X computer but not on a Windows 10 computer. Both running Node 8 and the same dependencies due to using a yarn.lock file.

Called ts-node-dev command ts-node-dev --respawn --type-check ./server/app.ts. If it makes a difference we did not follow the guideline of installing the package globally.

[kachkaev]

If it makes a difference we did not follow the guideline of installing the package globally.

All deps were in a local node_modules directory in my case too.

[wclr]

You may try the latest published version, maybe something will change, maybe not. )

[kachkaev]

Thanks for releasing the update @whitecolor! I switched to 1.0.0-pre.11, but unfortunately the error remained. My current workaround involves using nodemon, which is probably less efficient:

"scripts": {
    "watch": "nodemon --exec ts-node --ext ts --watch src",
    "watch:broken": "ts-node-dev --respawn --notify=false"
}

yarn watch src/actions/my-action.ts

[wclr]

@kachkaev is happening all the time in your project?

[kachkaev]

What is interesting is that the exception is thrown only for some of my project's entry points (aka actions). All of them work OK with nodemon, so it's not the case of a ts-node error that's just displayed in cryptic way by ts-node-dev . When I was trying to investigate which lines of code contribute to the failure by commenting them out in batches, I sometimes ended up the entire faulty action working correctly or with a crash (like in my first comment). It seems like the error behaviour is stateful, i.e. it depends on the code ran in the preceding attempts.

[wclr]

Yes, the problem is definitely with ts-node-dev, its probably because of way of interacting with child process and require hooks, maybe with some race conditions while process start, try it with the latest pre.12, added some timeout.

[kachkaev]

Thanks for looking into this Alex! Unfortunately, the exception is still the case in [email protected].

[wclr]

That's really strange to me, ok, maybe some I will be able to chase it down.

[Koslun]

As stated it works fine for me on Windows 10 but not for another colleague on Mac OS X. So that seems to be one common factor.

Other env details:

Node 8.9
yarn 1.3.2
ts-node 4.1.0
ts-node-dev 1.0.0-pre.11
typescript 2.7.1
macOS High Sierra v10.13.3

[testerez]

Same issue here. MacOS too.

[wclr]

Yes, I see the repetitive error now on a big file, I will try to figure out how to fix it.

[wclr]

I published new version check it, please.

[testerez]

It's working! 🎉
(And it's a lot faster than nodemon)

[kachkaev]

I can also confirm that I no longer see the error in 1.0.0-pre.15! 🎉 A huge thank you @whitecolor!

ts-node-dev is indeed blazing fast compared to nodemon + ts-node ❤️

[testerez]

It seams like it's not fully fixed. I just had the same issue while reloading on changes.
Worked after restarting ts-node-dev.

[wclr]

Hm, I probably know where the issue, it just requires more tricks to workaround, stay tuned.

[wclr]

@testerez Published fixed version. probably some time is needed to ensure that bug is not here anymore.

[testerez]

Cool, I'll update and let you know if it bugs again. Thanks!

[Falieson]

Fixed for me

[wclr]

Supposedly should work.

[petrdsvoboda]

I still have this issue on 1.0.0-pre.18. It happens right away when I start ts-node-dev

[wclr]

@ petrdsvoboda What is your OS, how big is a file that gives an error?

[petrdsvoboda]

I am using Arch Linux and the file is 365B

[wclr]

@petrdsvoboda what does the error says exactly. Does it works actually?

[petrdsvoboda]

The server isn't working at all. In the previous broken versions it would throw the error, start server and run in the background, but without live-reloading and I had to kill the process manually to quit ts-node-dev. Now it just throws the error, does nothing and I have to kill ts-node-dev. Running ts-node works normally.

This is my error output.

Error: watch /projectPath/node_modules/ramda/src/composeP.js ENOSPC
    at FSWatcher.start (fs.js:1409:19)
    at Object.fs.watch (fs.js:1435:11)
    at add (/projectPath/node_modules/filewatcher/index.js:74:34)
    at /projectPath/node_modules/filewatcher/index.js:93:5
    at FSReqWrap.oncomplete (fs.js:171:5)
ELIFECYCLE
1
[email protected] build:live: `ts-node-dev --respawn src/server.ts`
Exit status 1

Failed at the [email protected] build:live script.
This is probably not a problem with npm. There is likely additional logging output above.

A complete log of this run can be found in:
/logs/.npm/_logs/2018-03-07T12_11_49_827Z-debug.log
An unexpected error occurred: "Command failed.
Exit code: 1
Command: sh
Arguments: -c npm run build:live
Directory: /projectPath
Output:
".
Error: Could not require /projectPath/src/services/prototype/group.ts, compiled path:/tmp/.ts-node/compiled/src_services_prototype_group_ts_4823a52a1d422347b57cdab1ff4168f4eba16474f377cb7cc622406b458218ba.js
    at compile (/tmp/ts-node-dev-hook-1520424708762.js:30:13)
    at Module.m._compile (/tmp/ts-node-dev-hook-1520424708762.js:44:36)
    at Module._extensions..js (module.js:673:10)
    at require.extensions.(anonymous function) (/tmp/ts-node-dev-hook-1520424708762.js:46:14)
    at Object.nodeDevHook [as .ts] (/projectPath/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:575:32)
    at tryModuleLoad (module.js:515:12)
    at Function.Module._load (module.js:507:3)
    at Module.require (module.js:606:17)
    at require (internal/module.js:11:18)
    at Object.<anonymous> (/projectPath/src/reports/prototype/activeItems.ts:42:15)
    at Module._compile (module.js:662:30)
    at Module.m._compile (/tmp/ts-node-dev-hook-1520424708762.js:44:25)
    at Module._extensions..js (module.js:673:10)
    at require.extensions.(anonymous function) (/tmp/ts-node-dev-hook-1520424708762.js:46:14)
    at Object.nodeDevHook [as .ts] (/projectPath/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:575:32)
    at tryModuleLoad (module.js:515:12)
    at Function.Module._load (module.js:507:3)
    at Module.require (module.js:606:17)
    at require (internal/module.js:11:18)
    at Object.<anonymous> (/projectPath/src/controllers/prototype/orders.ts:43:21)

[wclr]

I'm not sure I believe this error Error: watch /projectPath/node_modules/ramda/src/composeP.js ENOSPC refers to the run?

Maybe this causes the issue, there is advices to fix it in linux with command:
echo fs.inotify.max_user_watches=524288 | sudo tee -a /etc/sysctl.conf && sudo sysctl -p

If you run some other TS script with ts-node-dev should it work?

[petrdsvoboda]

Increasing the user watches limit did the work. It's working normally now. Thank you

Sorry for bothering you with my errors. I saw this issue and I kinda automatically thought that it's related.

[wclr]

@petrdsvoboda ok, glad that it helped.

[aikoven]

Still getting this error on macOS when starting multiple Docker containers with ts-node-dev enabled.

My guess is that it happens because of timeThreshold being too small (10 seconds), especially when starting multiple apps in parallel on a slow machine.

[wclr]

My guess is that it happens because of timeThreshold being too small (10 seconds),

Hm, you may change it --compile-timeout 30000, but I believe that the reason is different, this timeout for compiling a single file, was for debugging purposes mostly. I may be wrong of course, you may try.

[aikoven]

@whitecolor it seems that you’re right, it didn’t fix the problem. Moreover, sometimes it happens immediately after start, even if I launch a single container.

[wclr]

@aikoven not sure I've seen the error this since was fixed.

[aikoven]

Setting compile timeout to 90 seconds seems to have fixed the issue for our case.

[wclr]

Setting compile timeout to 90 seconds seems to have fixed the issue for our case.

Do you know the file that causes the issue? (this timeout is for single file compilation).

[aikoven]

Here's the error message:

Error: Could not require /opt/app/src/index.ts, compiled path:/tmp/.ts-node/compiled/src_index_ts_77422fb8b702bc764b30afe40edb019b94fe582fc7d48fc5f171fbf1d04ef6b9.js
    at compile (/tmp/ts-node-dev-hook-1523337655467.js:30:13)
    at Module.m._compile (/tmp/ts-node-dev-hook-1523337655467.js:44:36)
    at Module._extensions..js (module.js:660:10)
    at require.extensions.(anonymous function) (/tmp/ts-node-dev-hook-1523337655467.js:46:14)
    at Object.nodeDevHook [as .ts] (/opt/app/node_modules/ts-node-dev/lib/hook.js:61:7)
    at Module.load (module.js:561:32)
    at tryModuleLoad (module.js:501:12)
    at Function.Module._load (module.js:493:3)
    at Module.require (module.js:593:17)
    at require (internal/module.js:11:18)
[ERROR] 05:21:02 Error: Could not require /opt/app/src/index.ts, compiled path:/tmp/.ts-node/compiled/src_index_ts_77422fb8b702bc764b30afe40edb019b94fe582fc7d48fc5f171fbf1d04ef6b9.js

[wclr]

@aikoven
I mean is this file big, etc? Is the error happens everytime, can it be reproduced?

[aikoven]

It’s not big at all, just an entrypoint for a microservice. It happens more often if I start multiple services simultaneously, which gives really high CPU load for about 0.5 – 1 minute before everything starts. Also, I can reproduce it every time if I set compile timeout to 1 second.

[wclr]

Well, in this case, I believe this is not a bug of ts-node-dev logic itself, though for me it is really strange that ts-compilation can take so much time. I'm not sure if we have to increase default timeout?

[aikoven]

Are there any drawbacks to increasing it? Like, is there a possibility that we'd reach the timeout due to an error, or would it abort immediately after an error happens?

Also, as far as I understand, we make a synchronous loop to wait for a compilation to complete, but this implies higher CPU load and thus slows down the compilation, pushing it closer to a timeout.

That said, we have a workaround and I'm satisfied with it for now. But IMO the best case scenario would be to somehow eliminate the need for timeouts at all.

Thank you for this amazing tool, auto-reload work unbelievably fast!

[wclr]

Are there any drawbacks to increasing it?

I think no.

we make a synchronous loop to wait for a compilation to complete

This is the hacky solution I have to invent, to wait for TS-compilation result from parent process during synchronous node module require in a child. I don't actually think that checking file existence takes many CPU resources, though I haven't checked cpu prolife, i'm not sure if there is possible more relaxed solution.

I'll reopen the issue till timeout increased/removed.

[aikoven]

I don't actually think that checking file existence takes many CPU resources

Not the checking itself, but since there's no sleep, the loop may iterate a lot of times before the file is created.

How about this: have a separate script that waits for a file via e.g. fs.watch(), then execute it with a blocking call to child_process.execFileSync()

[wclr]

@aikoven I think this a good idea really.

[nikkatalnikov]

any progress on Mac OS issue?

[wclr]

Ok, I've implemented @aikoven proposal for watching a compiled file, and removed timeout, so you may try how it works for you.