Progressively slower performance and high cpu usage

[TimNZ]

There is a 'leak' in likely the watching process - every time the process is restarted after a write, cpu utilisation increases until it is at 100% and I have to restart nodemon completely.

I don't have time in the short term to spend on this, but surely I'm not the only one experiencing it.

Win7 x64, node 0.8.x -> 0.10.x e.g. always been happening.

[remy]

Though strange that it's not been reported before (or perhaps it has...).

I assume you're seeing this same behaviour on a simple node process like:

require('http').createServer(function (res, res) {
  res.end('Hello');
}).listen(8000);

[TimNZ]

I wouldn't assume that, but I guess it could be automated to test by having a script that writes test.js every 10 seconds or so and seeing what happens.

In my case it is 100% replicable - at all times the restarts get slower and slower and eventually the node process is at 100%, but I haven't confirmed it is the nodemon process or the app.

Let me get back to you when I've got time to look at it in depth.

[tlvince]

I am intermittently experiencing this on OS X; with long running processes find maxes out at 100% CPU usage, perhaps related to #148.

[remy]

I'm not able to replicate this yet. I usually have a nodemon process running jsbin for dev - admittedly this example is only a few days old (4 days) but I've had much longer and it doesn't affect cpu:

» ps auxww | egrep 'nodemon|USER' | grep -v grep
USER             PID  %CPU %MEM      VSZ    RSS   TT  STAT STARTED      TIME COMMAND
remy           47987   0.1  1.2  3054896  50744 s002  S+   Thu12pm   6:03.44 node /usr/local/bin/nodemon

@tlvince do you have a sample app that you can see this 100% cpu issue?

[remy]

I've got a feeling this might be related to the number of files being processed. I've made a change to the latest dev version of nodemon that might mitigate this issue (if it's indeed linked to the file number). Any chance you can run the following command in the directory you normally run nodemon from?

find . | wc -l

And paste the result here?

[TimNZ]

8781, it's a lot. I was also thinking there may be a watcher leak on each restart.

[TimNZ]

I guess that wasn't directed at me, but I hope whatever you're looking at would apply to Windows as well.

[tlvince]

@remy, that sounds plausible:

❯ find . | wc -l
   44127

(Don't ask 😄)

[TimNZ]

Tom you win J

[remy]

Okay, so my gut feeling is that there's a lot of node_module dependancies (or deps of deps). If you're on linux, then this will go away. On mac we use find so I'll see if I can grep out the pattern, which I think will resolve the high cpu issue.

[tlvince]

Would this be mitigated through the use of fs.watch() (as per #148)?

[remy]

@tlvince can you run your find again without node_modules find . | grep -v node_modules | wc

I'm not sure applying fs.watch and creating a new event listener for potentially 44K files is going to be perform better. Which was why nodemon was always using unix find command to get a faster way of working out what had changed...

[tlvince]

Sure!:

❯ find . | grep -v node_modules | wc -l
    8310

node_modules looks like a good candidate to ignore by default.

[remy]

nodemon is ignoring node_modules/**/node_modules after discussion on #230.

That's still pretty high...

Can you replicate the CPU issue? If you can, can you install the current dev version (npm install -g nodemon@dev) and run nodemon in verbose mode nodemon -V and then replicate the issue and paste the output from nodemon. It should spew out the list of files that are triggering a restart.

[yoshuawuyts]

Just butting in to tell I'm experiencing the same issue. CPU caps at 94% though, 100% of the time.

[yoshuawuyts]

My grunt output from the nodemon@dev -v branch, run through grunt

Running "nodemon:dev" (nodemon) task                                                                      
Verifying property nodemon.dev exists in config...OK                                                      
File: [no files]                                                                                          
Options: args=[""], cwd="./", delayTime=1, env={"PORT":"1337"}, file="app.js", legacyWatch, nodeArgs=["--d
ebug"], watchedFolders=["./","api/"]                                                                      
15 Dec 13:13:17 - [nodemon] v0.7.10                                                                       
15 Dec 13:13:17 - [nodemon] to restart at any time, enter `rs`                                            
15 Dec 13:13:17 - [nodemon] watching: C:\Users\Yoshua\Documents\GitHub\express                            
15 Dec 13:13:17 - [nodemon] watching: C:\Users\Yoshua\Documents\GitHub\express\api                        
15 Dec 13:13:17 - [nodemon] starting `node --debug server.js app.js`                                      
debugger listening on port 5858                                                                           
connect.multipart() will be removed in connect 3.0                                                        
visit https://github.com/senchalabs/connect/wiki/Connect-3.0 for alternatives                             
connect.limit() will be removed in connect 3.0                                                            
Listening on port 1337                                                                                    

[tlvince]

Here's my nodemon@dev -V output if it helps.

[remy]

Can you test outside of grunt, just to reduce the number of variables. Do
you get the same high CPU?

On Sunday, December 15, 2013, Tom Vincent wrote:

Here's my nodemon@dev -V output https://gist.github.com/tlvince/7972549if it helps.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/205#issuecomment-30604479
.

— Remy

[remy]

Sorry - to clarify:

@yoshuawuyts can you take grunt out of the picture. You've got the dev version install, but because you're using grunt-nodemon it's got it's own dependancy, so you're still on the old one. Can you remove grunt entirely from the test since you're able to consistently reproduce the issue.

@tlvince is that all that's causing your high cpu usage?

[yoshuawuyts]

I've run a few tests, and it seems that disabling legacyWatch helped. Instead of staying at 95% CPU it peaks only right after a restart and then quickly drops back to normal levels. Needless to say: running it without Grunt also fixed the issue.

[remy]

@yoshuawuyts do you know why you were using legacyWatch mode?

[yoshuawuyts]

Since I'm using Windows and your docs state that fs.watch doesn't always work I included legacyWatch just for good measure.

[remy]

@yoshuawuyts actually fs.watch tends to work best on windows! legacyWatch tends to be for old linux machines. Did nodemon echo out that you should use the legacy switch or was it from online docs?

[tlvince]

@remy, Yes. htop output:

  PID USER       RES CPU% MEM% Command
42876 tom        760 94.0  0.0 find -L /Users/tom/Projects/src/node/fable -type f -mtime -115s -print

The find process is short-lived, but restarts every ~second, with a ~100% CPU spike.

[yoshuawuyts]

@remy I got it from the README. No echo's or anything :)

[remy]

@tlvince and this in off the directory that contains 44,000+ files, right?

[tlvince]

@remy correct.

[remy]

@tlvince so we need to run a find command that doesn't blow up your cpu. This'll be interesting :)

[remy]

@tlvince can you tell me how this performs - though I'm not even 100% sure of the -not support

find -L /Users/tom/Projects/src/node/fable -type f -mtime -115s -not -path "./.git/*" -not -path "./node_modules/**/node_modules/*" -print

Obviously you'll need to touch a file that you normally save right before running this command (or 115 seconds before running this command). How does that perform?

[tlvince]

That one doesn't give any noticeable improvement; it hovers around 90%.

How about leveraging Spotlight? The following will print files modified in the last second and it's lightning quick:

mdfind -onlyin . 'kMDItemContentModificationDate >= $time.now(-1)'

❯ time find -L . -type f -mtime -115s -not -path "./.git/*" -not -path "./node_modules/**/node_modules/*" -print
find -L . -type f -mtime -115s -not -path     0.18s user 2.52s system 76% cpu 3.538 total
❯ time mdfind -onlyin . 'kMDItemContentModificationDate >= $time.now(-1)'
mdfind -onlyin . 'kMDItemContentModificationDate >= $time.now(-1)'  0.01s user 0.01s system 10% cpu 0.246 total

[remy]

But only works for mac users and mac users that have spotlight enabled (I'm a mac user with spotlight disabled).

Hmmm. This is a pain (still looking at it - whilst also looking at Windows issues in the new code)

[remy]

@tlvince can you try:

time nice -20 find -L . -type f -mtime -115s -not -path "./.git/*" -not -path "./node_modules/**/node_modules/*" -print

[tlvince]

❯ time nice -20 find -L . -type f -mtime -115s -not -path "./.git/*" -not -path "./node_modules/**/node_modules/*" -print
nice -20 find -L . -type f -mtime -115s -not -path "./.git/*" -not -path    0.17s user 2.27s system 83% cpu 2.931 total

[remy]

Right, we have two "issues" here.

1. Progressively slower performance
2. High CPU on each monitor run

I believe nodemon@1.0.0 has fixed the progressively slow perf (1) because I found that the monitoring list was getting continuously larger and larger - something that's fixed now. If you had this issue, can you upgrade to the latest and let me know if I need to re-open this issue.

High CPU (2) due to 50,000+ files being monitored, I'm going to have to have to suggest maybe there's too many files being monitored. I can push the cpu down by using nice but that's not really a solution. @tlvince suggested using spotlight's own internal system - which I'm not keen on because it seems particularly bespoke, particularly if spotlight is disabled (which I do in my case because I find it horribly slow when it's indexing). If a new test and method can be added then I'd be open to merging in a pull request, but for now, I think @tlvince, you might be living on the extreme edge of what nodemon is sensibly capable of. That said, I'm totally open to continuing this in a separate thread.

[tlvince]

@remy, that's a sensible decision.

The offending project (containing ~50k files) is an outlier and I don't think there's much that can be done (in a robust way) to alleviate the CPU usage.

I've tried a few nodemon alternatives (run, supervisor) on this project and they both struggle in the same way. I did consider suggesting adding some tests to see if Spotlight is available and enabled, but didn't look into the details, and as you say, we should avoid bespoke solutions, although it might be worth looking into if this comes up again.

[remy]

@tlvince just as a heads up, I've modified nodemon@1.0.12 to include a warning when there's a large number of files being monitored. It's not much, but it'll certainly flag up any accidental watch.

[TimNZ]

Installed 1.0.3 on Windows 7x64 and now relatively high fluctuating cpu usage (always between 10->60% on one CPU) for the same large project. With 0.9.x I just had the slow down but little to no cpu usage on monitoring, with increasing slowness over time for restarts.

[crussell42]

Simple node program:
OSX 10.9.1 imac 2.66GHz intel core duo 2, 8 gig ram.
node v0.10.25
cpu usage for node process 150..160%

require('http').createServer(function (res, res) {
res.end('Hello');
}).listen(8000);

[remy]

@crussell42 run from an empty directory and no global config?

[crussell42]

Not sure on global config, I am a noob to node but this is just a empty dir
with an app.js only.
Upgraded to node 0.10.26 and cpu issue goes away on same app.
Full code for the simple test program was nothing more than the basic hello
world.

var http = require('http');

http.createServer(function (request,response) {
response.writeHead(200,{'Content-Type': 'text/plain'});
response.end('Hello World');
}).listen(8124);

console.log('Server running localhost:8124');

On Wed, Feb 19, 2014 at 10:55 AM, Remy Sharp notifications@github.comwrote:

@crussell42 https://github.com/crussell42 run from an empty directory
and no global config?

Reply to this email directly or view it on GitHubhttps://github.com//issues/205#issuecomment-35520692
.

[crussell42]

If this would help you debug something, I can downgrade back to 10.25 and
try and reproduce.

On Wed, Feb 19, 2014 at 11:13 AM, Chris Russell crussell42@gmail.comwrote:

Not sure on global config, I am a noob to node but this is just a empty
dir with an app.js only.
Upgraded to node 0.10.26 and cpu issue goes away on same app.
Full code for the simple test program was nothing more than the basic
hello world.

var http = require('http');

http.createServer(function (request,response) {
response.writeHead(200,{'Content-Type': 'text/plain'});
response.end('Hello World');
}).listen(8124);

console.log('Server running localhost:8124');

On Wed, Feb 19, 2014 at 10:55 AM, Remy Sharp notifications@github.comwrote:

@crussell42 https://github.com/crussell42 run from an empty directory
and no global config?

Reply to this email directly or view it on GitHubhttps://github.com//issues/205#issuecomment-35520692
.

[crussell42]

Just to let you know, the CPU spike does occur in version 0.10.26 but
only when node is run in an Emacs sub-shell (ala meta-x-shell).
In a osx terminal I do not get the CPU spike.
Must be some sort issue with how the emacs shell treats or pipes io to/from
sub processes in the shell buffer.

Intrestingly:
Same OSX 10.9.1 box running virtualbox client ubuntu 12.4
I do not get the emacs sub-shell node cpu spike.

So looks like an emacs issue, sorry for the disturbance and thanks for
quick reply.

On Wed, Feb 19, 2014 at 11:23 AM, Chris Russell crussell42@gmail.comwrote:

If this would help you debug something, I can downgrade back to 10.25 and
try and reproduce.

On Wed, Feb 19, 2014 at 11:13 AM, Chris Russell crussell42@gmail.comwrote:

Not sure on global config, I am a noob to node but this is just a empty
dir with an app.js only.
Upgraded to node 0.10.26 and cpu issue goes away on same app.
Full code for the simple test program was nothing more than the basic
hello world.

var http = require('http');

http.createServer(function (request,response) {
response.writeHead(200,{'Content-Type': 'text/plain'});
response.end('Hello World');
}).listen(8124);

console.log('Server running localhost:8124');

On Wed, Feb 19, 2014 at 10:55 AM, Remy Sharp notifications@github.comwrote:

@crussell42 https://github.com/crussell42 run from an empty directory
and no global config?

Reply to this email directly or view it on GitHubhttps://github.com//issues/205#issuecomment-35520692
.

[DotFreelance]

I want to note that this issue also occurs when starting the process from upstart for some reason. I don't think we can make any claims that nodemon is suitable as an actual daemon in any sort of production capacity. I'm seeing load averages of 2400 or higher, absolutely crippling.

[remy]

I'm certain that I've never recommended nodemon for production. In fact,
I've discouraged it when I've come across it.

nodemon is squarely a development tool.
On 1 May 2015 00:47, "DotFreelance" notifications@github.com wrote:

I want to note that this issue also occurs when starting the process from
upstart for some reason. I don't think we can make any claims that nodemon
is suitable as an actual daemon in any sort of production capacity. I'm
seeing load averages of 2400 or higher, absolutely crippling.

—
Reply to this email directly or view it on GitHub
#205 (comment).