remy / nodemon

Monitor for any changes in your node.js application and automatically restart the server - perfect for development
http://nodemon.io/
MIT License
26.22k stars 1.72k forks source link

Bug report: Execution option run twice instead of one #349

Closed mondwan closed 6 years ago

mondwan commented 10 years ago

I run following command $> nodemon --ext lua --exec 'lunit test/test_SetCommandAdapter.lua'

For first run, so far so good

6 Jun 10:19:17 - [nodemon] v1.2.0
6 Jun 10:19:17 - [nodemon] to restart at any time, enter `rs`
6 Jun 10:19:17 - [nodemon] watching: *.*
6 Jun 10:19:17 - [nodemon] starting `lunit test/test_SetCommandAdapter.lua`
Loaded testsuite with 3 tests in 1 testcases.

    ...

12 Assertions checked.

Testsuite finished (3 passed, 0 failed, 0 errors).
6 Jun 10:19:17 - [nodemon] clean exit - waiting for changes before restart

However, if there is any file changes, nodemon runs execution twice.

6 Jun 10:19:17 - [nodemon] clean exit - waiting for changes before restart
6 Jun 10:21:03 - [nodemon] restarting due to changes...
6 Jun 10:21:03 - [nodemon] starting `lunit test/test_SetCommandAdapter.lua`
Loaded testsuite with 3 tests in 1 testcases.

    ...

12 Assertions checked.

Testsuite finished (3 passed, 0 failed, 0 errors).
6 Jun 10:21:03 - [nodemon] clean exit - waiting for changes before restart
6 Jun 10:21:03 - [nodemon] restarting due to changes...
6 Jun 10:21:03 - [nodemon] starting `lunit test/test_SetCommandAdapter.lua`
Loaded testsuite with 3 tests in 1 testcases.

    ...

12 Assertions checked.

Testsuite finished (3 passed, 0 failed, 0 errors).
6 Jun 10:21:03 - [nodemon] clean exit - waiting for changes before restart

Interestingly, no problems on typing rs manually.

6 Jun 10:21:03 - [nodemon] clean exit - waiting for changes before restart
rs
6 Jun 10:21:32 - [nodemon] starting `lunit test/test_SetCommandAdapter.lua`
Loaded testsuite with 3 tests in 1 testcases.

    ...

12 Assertions checked.

Testsuite finished (3 passed, 0 failed, 0 errors).
6 Jun 10:21:32 - [nodemon] clean exit - waiting for changes before restart
remy commented 10 years ago

I'm not a lua user, so can you provide a simplified version of your code so that I can replicate the issue and debug on my side?

In addition, could you replicate your test with -V (which give us verbose information about why it restarted.

mondwan commented 10 years ago

Ah... let me give you the verbose information

command: nodemon --ext lua --exec 'lunit test/test_Array.lua' -V

first run

6 Jun 14:30:42 - [nodemon] v1.2.0
6 Jun 14:30:42 - [nodemon] to restart at any time, enter `rs`
6 Jun 14:30:42 - [nodemon] ignoring: /home/mondwan/Documents/github/lua-p2manager/.git/**/* node_modules bower_components .sass-cache
6 Jun 14:30:42 - [nodemon] watching: *.*
6 Jun 14:30:42 - [nodemon] watching extensions: lua
6 Jun 14:30:42 - [nodemon] starting `lunit test/test_Array.lua`
6 Jun 14:30:42 - [nodemon] child pid: 28386
Loaded testsuite with 2 tests in 1 testcases.

    ..

4 Assertions checked.

Testsuite finished (2 passed, 0 failed, 0 errors).
6 Jun 14:30:42 - [nodemon] clean exit - waiting for changes before restart
6 Jun 14:30:42 - [nodemon] watching 126 files

On File changes

6 Jun 14:30:42 - [nodemon] watching 126 files
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/4913
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/0
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/4913
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/0
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/4913
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/0
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/Array.lua
6 Jun 14:31:03 - [nodemon] matched rule: **/*.*
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/1
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/Array.lua~
6 Jun 14:31:03 - [nodemon] matched rule: **/*.*
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/0
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/Array.lua
6 Jun 14:31:03 - [nodemon] matched rule: **/*.*
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/1
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/Array.lua
6 Jun 14:31:03 - [nodemon] matched rule: **/*.*
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/1
6 Jun 14:31:03 - [nodemon] restarting due to changes...
6 Jun 14:31:03 - [nodemon] src/Utility/Array.lua

6 Jun 14:31:03 - [nodemon] starting `lunit test/test_Array.lua`
6 Jun 14:31:03 - [nodemon] child pid: 28392
Loaded testsuite with 2 tests in 1 testcases.

    ..

4 Assertions checked.

Testsuite finished (2 passed, 0 failed, 0 errors).
6 Jun 14:31:03 - [nodemon] clean exit - waiting for changes before restart
6 Jun 14:31:03 - [nodemon] watching 127 files
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/Array.lua
6 Jun 14:31:03 - [nodemon] matched rule: **/*.*
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/1
6 Jun 14:31:03 - [nodemon] files triggering change check: src/Utility/Array.lua~
6 Jun 14:31:03 - [nodemon] matched rule: **/*.*
6 Jun 14:31:03 - [nodemon] changes after filters (before/after): 1/0
6 Jun 14:31:03 - [nodemon] restarting due to changes...
6 Jun 14:31:03 - [nodemon] src/Utility/Array.lua

6 Jun 14:31:03 - [nodemon] starting `lunit test/test_Array.lua`
6 Jun 14:31:03 - [nodemon] child pid: 28400
Loaded testsuite with 2 tests in 1 testcases.

    ..

4 Assertions checked.

Testsuite finished (2 passed, 0 failed, 0 errors).
6 Jun 14:31:03 - [nodemon] clean exit - waiting for changes before restart
6 Jun 14:31:03 - [nodemon] watching 126 files
6 Jun 14:31:07 - [nodemon] files triggering change check: src/Utility/.Array.lua.swp
6 Jun 14:31:07 - [nodemon] changes after filters (before/after): 1/0

manually restart

6 Jun 14:31:07 - [nodemon] changes after filters (before/after): 1/0
rs
6 Jun 14:31:56 - [nodemon] starting `lunit test/test_Array.lua`
6 Jun 14:31:56 - [nodemon] child pid: 28406
Loaded testsuite with 2 tests in 1 testcases.

    ..

4 Assertions checked.

Testsuite finished (2 passed, 0 failed, 0 errors).
6 Jun 14:31:56 - [nodemon] clean exit - waiting for changes before restart
6 Jun 14:31:56 - [nodemon] watching 126 files

After reading a while, maybe those *.swp files are the root cause of this bug. (I am using VIM :D)

For an easier example, I just try this nodemon -V --ext py --exec 'python a.py'

contents in a.py print 'haha'

Same effect

remy commented 10 years ago

Hmm. Using your python example means it's easier to test. Here's what I see:

screen shot 2014-06-06 at 17 13 45

Notice that it only restarts once. What are you seeing?


Looking at your log closers, it looks like the same file is causing the restart. The only way that might happen is if there's an issue with the timestamping...

It /might/ be that find isn't working as expected on your OS. I'm guessing Mac (based on the paths) - what version?

mondwan commented 10 years ago

Which editor you are using? Mine is vim. There are swp files which like (6 Jun 14:31:07 - [nodemon] files triggering change check: src/Utility/.Array.lua.swp)

I guess, when I press :w (save file) both of files (Array.lua and .Array.lua.swp) will be updated.

Btw, My development environment is Ubuntu 12.04

mondwan commented 10 years ago

Currently, I am trying to solve this issue.... I found that there are no such issue on OS ubuntu 14.04 and mac OSX 10.09 while there does on Ubuntu 12.04.

The testing environment likes following bugfix/ bugfix/a.py bugfix/b.py

#a.py
print '*******'
print 'This is file |%s|' % __file__
print '*******'

Run nodemon in this way

nodemon ext py --exec 'python a.py' -V

MAC OS X and ubuntu 14.04 runs as expected.

Here is the abnormal output from ubuntu 12.04

>21 Jun 16:14:30 - [nodemon] v1.2.0
21 Jun 16:14:30 - [nodemon] to restart at any time, enter `rs`
21 Jun 16:14:30 - [nodemon] ignoring: .git node_modules bower_components .sass-cache
21 Jun 16:14:30 - [nodemon] watching: *.*
21 Jun 16:14:30 - [nodemon] watching extensions: py
21 Jun 16:14:30 - [nodemon] starting `python a.py`
21 Jun 16:14:30 - [nodemon] child pid: 26181
21 Jun 16:14:30 - [nodemon] watching 2 files
*************************
This is file |a.py|
*************************
21 Jun 16:14:30 - [nodemon] clean exit - waiting for changes before restart

<<<< Trigger changes manually >>>>>
21 Jun 16:14:32 - [nodemon] files triggering change check: .a.py.swp
21 Jun 16:14:32 - [nodemon] changes after filters (before/after): 1/0
21 Jun 16:14:34 - [nodemon] files triggering change check: 4913
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/0
21 Jun 16:14:34 - [nodemon] files triggering change check: 4913
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/0
21 Jun 16:14:34 - [nodemon] files triggering change check: 4913
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/0
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/1
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py~
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/0
21 Jun 16:14:34 - [nodemon] restarting due to changes...
21 Jun 16:14:34 - [nodemon] a.py

21 Jun 16:14:34 - [nodemon] starting `python a.py`
21 Jun 16:14:34 - [nodemon] child pid: 26185
21 Jun 16:14:34 - [nodemon] watching 2 files
python: can't open file 'a.py': [Errno 2] No such file or directory

21 Jun 16:14:34 - [nodemon] app crashed - waiting for file changes before starting...
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/1
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/1
21 Jun 16:14:34 - [nodemon] restarting due to changes...
21 Jun 16:14:34 - [nodemon] a.py

21 Jun 16:14:34 - [nodemon] starting `python a.py`
21 Jun 16:14:34 - [nodemon] child pid: 26189
21 Jun 16:14:34 - [nodemon] watching 3 files
*************************
This is file |a.py|
*************************
21 Jun 16:14:34 - [nodemon] clean exit - waiting for changes before restart
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/1
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/1
21 Jun 16:14:34 - [nodemon] files triggering change check: a.py~
21 Jun 16:14:34 - [nodemon] matched rule: **/*.*
21 Jun 16:14:34 - [nodemon] changes after filters (before/after): 1/0
21 Jun 16:14:34 - [nodemon] restarting due to changes...
21 Jun 16:14:34 - [nodemon] a.py

21 Jun 16:14:34 - [nodemon] starting `python a.py`
21 Jun 16:14:34 - [nodemon] child pid: 26193
21 Jun 16:14:34 - [nodemon] watching 2 files
*************************
This is file |a.py|
*************************
21 Jun 16:14:34 - [nodemon] clean exit - waiting for changes before restart
21 Jun 16:14:38 - [nodemon] files triggering change check: .a.py.swp
21 Jun 16:14:38 - [nodemon] changes after filters (before/after): 1/0

Actually, it runs triple time instead of twice. 1st run: python: can't open file 'a.py': [Errno 2] No such file or directory while the 2nd and 3rd run correctly.

Any hints for me to trace this issue???

remy commented 10 years ago

Can you post the output of

nodemon ext py --exec 'python a.py' -V --dump
mondwan commented 10 years ago
21 Jun 17:33:14 - [nodemon] v1.2.0
21 Jun 17:33:14 - [nodemon] to restart at any time, enter `rs`
21 Jun 17:33:14 - [nodemon] ignoring: .git node_modules bower_components .sass-cache
21 Jun 17:33:14 - [nodemon] watching: *.*
21 Jun 17:33:14 - [nodemon] watching extensions: py
--------------
node: v0.10.26
nodemon: v1.2.0
command: node /usr/bin/nodemon --ext py --exec python a.py -V --dump
cwd: /home/mondwan/Documents/codeTest/nodemon-bugfix
OS: linux x64
--------------
{ run: false,
  system: 
   { cwd: '/home/mondwan/Documents/codeTest/nodemon-bugfix',
     useFind: false,
     useWatch: true,
     useWatchFile: false },
  required: false,
  dirs: [ '/home/mondwan/Documents/codeTest/nodemon-bugfix' ],
  timeout: 1000,
  options: 
   { scriptPosition: null,
     ext: 'py',
     exec: 'python a.py',
     verbose: true,
     dump: true,
     script: null,
     args: [],
     ignore: 
      [ '.git',
        'node_modules',
        'bower_components',
        '.sass-cache',
        re: /\.git|node_modules|bower_components|\.sass\-cache/ ],
     watch: [ '*.*', re: /.*\..*/ ],
     restartable: 'rs',
     execMap: { py: 'python', rb: 'ruby' },
     stdin: true,
     stdout: true,
     execOptions: 
      { script: null,
        exec: 'python',
        args: [],
        nodeArgs: undefined,
        ext: 'py',
        env: {},
        execArgs: [ 'a.py' ] },
     monitor: 
      [ '*.*',
        '!.git',
        '!node_modules',
        '!bower_components',
        '!.sass-cache' ] },
  load: [Function],
  reset: [Function: reset],
  lastStarted: 0,
  loaded: [],
  command: 
   { raw: { executable: 'python', args: [ 'a.py' ] },
     string: 'python a.py' } }
--------------
21 Jun 17:33:14 - [nodemon] exiting
mondwan commented 10 years ago

By the way, just now I have do another testing about the text editor.

Same environment... OS ubuntu 12.04 Every saving operations cause this issue effectively on VIM. However, no such problems on pico

edi9999 commented 9 years ago

Same issue for me on vim, even when using no plugins at all using this starting command:

vim -u NONE file.py

Do you have found anything that would cause that ?

edi9999 commented 9 years ago

Seems that the error is due to vim, I've asked the question on stackoverflow. It's not solved completely however: http://stackoverflow.com/questions/27782476/vim-is-triggering-multiple-saves

I still get two updates everytime

mondwan commented 9 years ago

What OS you are using?

IMO, the VIM backup mechanism (swp, swo etc) is the root cause for this issue.

In my past trials, without specify the extension in nodemon, for example --ext lua, you can trigger more than 2 times of runs due to swp, swo etc. (I forgot the detail since this was long long time ago)

I have tried to turn off those backup mechanism (:set something off etc). None of that solve the problem fully (Difference between triggering 3 times or 2 times).

Interestingly, there are no such problems in Ubuntu 14.04 and MAC OSX.

edi9999 commented 9 years ago

I'm on ubuntu 14.10, and setting all options as off didn't helped

I set the following in my .vimrc

set noswapfile set nobackup set nowritebackup set backupskip

eexit commented 8 years ago

I got the same issue with:

dacodekid commented 8 years ago

I'm having the same issue. It triggers twice for .js files. But changing a (package).json file, triggers normally.

jewirth commented 8 years ago

I noticed the same issue often but interestingly, it sometimes triggers three times (see output below) on my system and sometimes two times. Very rarely, it triggers one time. All three cases using the same configuration:

The directory where nodemon is being called only contains one javascript file and my editor does not create backup copies. Here's the output:

macy:testdir jens$ cat foo.js 
console.log('Hello');

macy:testdir jens$ ls -laT
total 8
drwxr-xr-x   3 jens  staff   102 Dec  4 08:00:27 2015 .
drwx------+ 39 jens  staff  1326 Dec  4 08:00:45 2015 ..
-rw-r--r--   1 jens  staff    22 Dec  4 08:00:23 2015 foo.js

macy:testdir jens$ nodemon foo.js 
[nodemon] 1.8.1
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node foo.js`
Hello
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 1st time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 1st time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 2nd time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 2nd time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 2nd time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 3rd time) Notice how it triggers thrice above?
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 3rd time) Notice how it triggers thrice above?
[nodemon] clean exit - waiting for changes before restart
[nodemon] restarting due to changes...
[nodemon] starting `node foo.js`
Hello (saved again 3rd time) Notice how it triggers thrice above?
[nodemon] clean exit - waiting for changes before restart
^Cmacy:testdir jens$

macy:testdir jens$ cat foo.js 
console.log('Hello (saved again 3rd time) Notice how it triggers thrice above?');

macy:testdir jens$ ls -laT
total 8
drwxr-xr-x   3 jens  staff   102 Dec  4 08:00:27 2015 .
drwx------+ 39 jens  staff  1326 Dec  4 08:00:45 2015 ..
-rw-r--r--   1 jens  staff    82 Dec  4 08:03:47 2015 foo.js
macy:testdir jens$

Here is another run using nodemon -V. It also shows a thrice trigger:

macy:testdir jens$ nodemon -V foo.js 
[nodemon] 1.8.1
[nodemon] to restart at any time, enter `rs`
[nodemon] ignoring: .git node_modules bower_components .sass-cache
[nodemon] watching: *.*
[nodemon] watching extensions: js,json
[nodemon] starting `node foo.js`
[nodemon] child pid: 47925
[nodemon] watching 1 files
Hello
[nodemon] clean exit - waiting for changes before restart
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47926
Hello (saved again 1st time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47927
Hello (saved again 1st time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47928
Hello (saved again 1st time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47929
Hello (saved again 2nd time)
[nodemon] clean exit - waiting for changes before restart
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47930
Hello (saved again 2nd time)
[nodemon] clean exit - waiting for changes before restart
^C[nodemon] exiting
macy:testdir jens$ 

Found out one more thing: A thrice trigger in which one child was unable to write to stdout:

[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47903
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47906
Hello World out there
[nodemon] clean exit - waiting for changes before restart
[nodemon] files triggering change check: foo.js
[nodemon] matched rule: **/*.*
[nodemon] changes after filters (before/after): 1/1
[nodemon] restarting due to changes...
[nodemon] foo.js

[nodemon] starting `node foo.js`
[nodemon] child pid: 47907
Hello World out there
[nodemon] clean exit - waiting for changes before restart

This is my nodemon -V --dump foo.jsoutput:

macy:testdir jens$ nodemon -V --dump foo.js 
[nodemon] 1.8.1
[nodemon] to restart at any time, enter `rs`
[nodemon] ignoring: .git node_modules bower_components .sass-cache
[nodemon] watching: *.*
[nodemon] watching extensions: js,json
--------------
node: v5.1.0
nodemon: 1.8.1
command: /usr/local/bin/node /usr/local/bin/nodemon -V --dump foo.js
cwd: /Users/jens/Desktop/testdir
OS: darwin x64
--------------
{ run: false,
  system: { cwd: '/Users/jens/Desktop/testdir' },
  required: false,
  dirs: [ '/Users/jens/Desktop/testdir' ],
  timeout: 1000,
  options: 
   { verbose: true,
     dump: true,
     ignore: 
      [ '.git',
        'node_modules',
        'bower_components',
        '.sass-cache',
        re: /\.git|node_modules|bower_components|\.sass\-cache/ ],
     watch: [ '*.*', re: /.*\..*/ ],
     ignoreRoot: [ '.git', 'node_modules', 'bower_components', '.sass-cache' ],
     restartable: 'rs',
     colours: true,
     execMap: { py: 'python', rb: 'ruby' },
     stdin: true,
     runOnChangeOnly: false,
     stdout: true,
     execOptions: 
      { script: 'foo.js',
        exec: 'node',
        args: [],
        scriptPosition: 0,
        nodeArgs: undefined,
        ext: 'js,json',
        env: {},
        execArgs: [] },
     monitor: 
      [ '*.*',
        '!.git',
        '!node_modules',
        '!bower_components',
        '!.sass-cache' ] },
  load: [Function],
  reset: [Function: reset],
  lastStarted: 0,
  loaded: [],
  watchInterval: null,
  command: 
   { raw: { executable: 'node', args: [ 'foo.js' ] },
     string: 'node foo.js' } }
--------------
[nodemon] exiting

I hope this contributes narrowing it down.

remy commented 8 years ago

Can you repeat with node 4? To rule out the node 5 factor?

On Fri, 4 Dec 2015 09:21 Jens Wirth notifications@github.com wrote:

I noticed the same issue often but interestingly, it sometimes triggers three times (see output below) on my system and sometimes two times. Very rarely, it triggers one time. All three cases using the same configuration:

  • OS X 10.11.1 (15B42)
  • Sublime Text 2 (Version 2.0.2, Build 2221)
  • Nodemon 1.8.1
  • v5.1.0

The directory where nodemon is being called only contains one javascript file and my editor does not create backup copies. Here's the output:

macy:testdir jens$ cat foo.js console.log('Hello');

macy:testdir jens$ ls -laT total 8 drwxr-xr-x 3 jens staff 102 Dec 4 08:00:27 2015 . drwx------+ 39 jens staff 1326 Dec 4 08:00:45 2015 .. -rw-r--r-- 1 jens staff 22 Dec 4 08:00:23 2015 foo.js

macy:testdir jens$ nodemon foo.js [nodemon] 1.8.1 [nodemon] to restart at any time, enter rs [nodemon] watching: . [nodemon] starting node foo.js Hello [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 1st time) [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 1st time) [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 2nd time) [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 2nd time) [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 2nd time) [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 3rd time) Notice how it triggers thrice above? [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 3rd time) Notice how it triggers thrice above? [nodemon] clean exit - waiting for changes before restart [nodemon] restarting due to changes... [nodemon] starting node foo.js Hello (saved again 3rd time) Notice how it triggers thrice above? [nodemon] clean exit - waiting for changes before restart ^Cmacy:testdir jens$

macy:testdir jens$ cat foo.js console.log('Hello (saved again 3rd time) Notice how it triggers thrice above?');

macy:testdir jens$ ls -laT total 8 drwxr-xr-x 3 jens staff 102 Dec 4 08:00:27 2015 . drwx------+ 39 jens staff 1326 Dec 4 08:00:45 2015 .. -rw-r--r-- 1 jens staff 82 Dec 4 08:03:47 2015 foo.js macy:testdir jens$

Here is another run using nodemon -V. It also shows a thrice trigger:

macy:testdir jens$ nodemon -V foo.js [nodemon] 1.8.1 [nodemon] to restart at any time, enter rs [nodemon] ignoring: .git node_modules bowercomponents .sass-cache [nodemon] watching: . [nodemon] watching extensions: js,json [nodemon] starting node foo.js [nodemon] child pid: 47925 [nodemon] watching 1 files Hello [nodemon] clean exit - waiting for changes before restart [nodemon] files triggering change check: foo.js [nodemon] matched rule: */_.* [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47926 Hello (saved again 1st time) [nodemon] clean exit - waiting for changes before restart [nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47927 Hello (saved again 1st time) [nodemon] clean exit - waiting for changes before restart [nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47928 Hello (saved again 1st time) [nodemon] clean exit - waiting for changes before restart [nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47929 Hello (saved again 2nd time) [nodemon] clean exit - waiting for changes before restart [nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47930 Hello (saved again 2nd time) [nodemon] clean exit - waiting for changes before restart ^C[nodemon] exiting macy:testdir jens$

Found out one more thing: A thrice trigger in which one child was unable to write to stdout:

[nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47903 [nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47906 Hello World out there [nodemon] clean exit - waiting for changes before restart [nodemon] files triggering change check: foo.js [nodemon] matched rule: /. [nodemon] changes after filters (before/after): 1/1 [nodemon] restarting due to changes... [nodemon] foo.js

[nodemon] starting node foo.js [nodemon] child pid: 47907 Hello World out there [nodemon] clean exit - waiting for changes before restart

This is my nodemon -V --dump foo.jsoutput:

macy:testdir jens$ nodemon -V --dump foo.js [nodemon] 1.8.1 [nodemon] to restart at any time, enter rs [nodemon] ignoring: .git node_modules bowercomponents .sass-cache [nodemon] watching: ._

[nodemon] watching extensions: js,json

node: v5.1.0 nodemon: 1.8.1 command: /usr/local/bin/node /usr/local/bin/nodemon -V --dump foo.js cwd: /Users/jens/Desktop/testdir

OS: darwin x64

{ run: false, system: { cwd: '/Users/jens/Desktop/testdir' }, required: false, dirs: [ '/Users/jens/Desktop/testdir' ], timeout: 1000, options: { verbose: true, dump: true, ignore: [ '.git', 'node_modules', 'bower_components', '.sass-cache', re: /.git|node_modules|bowercomponents|.sass-cache/ ], watch: [ '.', re: /..._/ ], ignoreRoot: [ '.git', 'node_modules', 'bowercomponents', '.sass-cache' ], restartable: 'rs', colours: true, execMap: { py: 'python', rb: 'ruby' }, stdin: true, runOnChangeOnly: false, stdout: true, execOptions: { script: 'foo.js', exec: 'node', args: [], scriptPosition: 0, nodeArgs: undefined, ext: 'js,json', env: {}, execArgs: [] }, monitor: [ '._', '!.git', '!node_modules', '!bower_components', '!.sass-cache' ] }, load: [Function], reset: [Function: reset], lastStarted: 0, loaded: [], watchInterval: null, command: { raw: { executable: 'node', args: [ 'foo.js' ] },

string: 'node foo.js' } }

[nodemon] exiting

I hope this contributes narrowing it down.

— Reply to this email directly or view it on GitHub https://github.com/remy/nodemon/issues/349#issuecomment-161917314.

jewirth commented 8 years ago

You got it! It doesn't happen with v4.2.3 LTS.

However, I dug a bit deeper and found out that it might have to do something with the kqueue filesystem event system. Why? I used fswatch (https://github.com/emcrisostomo/fswatch) which allows to observe file changes and to choose different ways to do so depending on the OS you are running. On OS X, it's FSevents, kqueue and polling. I used these steps to reproduce this nodemon issue's behavior exactly with fswatch:

fswatch -o foo.js will print "1" and a newline for each detected change event.

So I piped this to xargs and called date to get a timestamp for each event:

macy:testdir jens$ fswatch -o foo.js | xargs -P8 -I'{}' -n1 date
Fri Dec  4 11:31:26 CET 2015
Fri Dec  4 11:31:30 CET 2015
Fri Dec  4 11:31:34 CET 2015

Okay, I saved it 3 times in 4 seconds intervals. That's what I did, no problem here.

On OS X, fswatch uses FSEvents as default monitor. Now let's change this to polling:

macy:testdir jens$ fswatch --monitor=poll_monitor -o foo.js | xargs -P8 -I'{}' -n1 date
Fri Dec  4 11:40:46 CET 2015
Fri Dec  4 11:40:50 CET 2015
Fri Dec  4 11:40:54 CET 2015

Again, the output shows exactly what I did. No problem here, too.

Now let's see what using kqueue as monitor will result in:

macy:testdir jens$ fswatch --monitor=kqueue_monitor -o foo.js | xargs -P8 -I'{}' -n1 date
Fri Dec  4 11:43:11 CET 2015 <-- file saved here
Fri Dec  4 11:43:11 CET 2015
Fri Dec  4 11:43:12 CET 2015
Fri Dec  4 11:43:14 CET 2015 <-- file saved here
Fri Dec  4 11:43:14 CET 2015
Fri Dec  4 11:43:15 CET 2015
Fri Dec  4 11:43:17 CET 2015 <-- file saved here
Fri Dec  4 11:43:17 CET 2015
Fri Dec  4 11:43:18 CET 2015

Whoops, there we go! I modified the file at second 11, 14 and 17 but we got 9 events from that monitor.

Now I wanted to see the timestamp of those events in a more detailed resolution but I couldn't find a way to see milliseconds using the OS X's date tool. So I created my own unix timestamp tool:

// this is getTimestamp.c
#include <stdio.h>
#include <sys/time.h>

int main(void) {
    struct timeval time;
    gettimeofday(&time, NULL);
    printf("%lds %03ums %03uus\r\n", time.tv_sec,
        time.tv_usec/1000, time.tv_usec-time.tv_usec/1000*1000);
    return 0;
}

Compile with gcc getTimestamp.c -o getTimestamp It tells us the current time as Unix time including milliseconds and microseconds:

macy:testdir jens$ ./getTimestamp 
1449222463s 216ms 388us
macy:testdir jens$ 

Now, let's use this with fswatch and the kqueue monitor:

macy:testdir jens$ fswatch --monitor=kqueue_monitor -o foo.js | xargs -P8 -I'{}' -n1 getTimestamp
1449226110s 019ms 329us <-- file saved here
1449226110s 019ms 972us
1449226111s 060ms 956us
1449226114s 082ms 690us <-- file saved here
1449226114s 083ms 394us
1449226115s 286ms 731us
1449226118s 755ms 309us <-- file saved here
1449226118s 755ms 928us
1449226119s 960ms 446us

There we have a nice timing sequence of the events. The annoying 'ghost'-event comes twice. First within less than 1 millisecond and then again after a second. The latter one is what we notice here with nodemon regularly. The first one is so fast, that it appears only sometimes affects nodemon sometimes but not always and not for everyone . This fits 100% to my nodemon behavior with Node.js 5.

Paradoxically, according to the documentation, Node 4.2.3 as well as 5.1.1 are using kqueue for files on OS X: https://nodejs.org/docs/v5.1.1/api/fs.html#fs_availability https://nodejs.org/docs/v4.2.3/api/fs.html#fs_availability

This might be a single symptom with multiple roots. Of course, the backup-file by Vim users is another root and maybe there are more. But looks like I can't proof kqueue is a root, even if that's the case for fswatch. Maybe the Node.js docs for 5.1.1 are not correct?

lourd commented 8 years ago

I'm seeing this bug as well:

Doesn't happy when I switch back to Node v4.2.1. Without digging too far, I've seen it run twice for .js and .py files, but not .json files.

jhohlfeld commented 8 years ago

I got the same issue:

$ nodemon -w test.js --exec 'echo TEST'
[nodemon] 1.8.1
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: test.js
[nodemon] starting `echo TEST`
TEST
[nodemon] clean exit - waiting for changes before restart

Now while touching the file triggers just one restart, an echo-append results in two restarts:

$ touch test.js # triggers once
$ echo "testing.." > test.js # triggers twice
linus-amg commented 8 years ago

same issue

maximedupre commented 8 years ago

On my side, it wasn't working with node v4.4.3. I installed node v5.10.1 Stable and then it started to work normally.

stale[bot] commented 6 years ago

This issue has been automatically marked as idle and stale because it hasn't had any recent activity. It will be automtically closed if no further activity occurs. If you think this is wrong, or the problem still persists, just pop a reply in the comments and @remy will (try!) to follow up. Thank you for contributing <3

Stradivario commented 6 years ago

I have the same issue with node 8.9.0 ubuntu 17.10

I will post some more details when i get them regards

@remy

remy commented 6 years ago

Thanks. Do make sure it's on a new issue as I (try) to have a policy of leaving closed issues alone.

On Sat, 3 Mar 2018, 22:40 Stradivario, notifications@github.com wrote:

I have the same issue with node 8.9.0 ubuntu 17.10

I will post some more details when i get them regards

@remy https://github.com/remy

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/remy/nodemon/issues/349#issuecomment-370185713, or mute the thread https://github.com/notifications/unsubscribe-auth/AAA1hMU12GO54W94KITMbn8XEosEWOw5ks5taxvFgaJpZM4CBr9y .