Bug 1038492

From what I understand, all supervisor does is spawn a child process ("node server.js" in our case) and it will restart the child process when files it's watching are modified. This means there will be a small window of downtime, even when using supervisor.

Reassigning to Mrunal for review/comments.

It looks like to npm build process is what's taking node (supervisor) down

Watching the log a deploy, looks like the repo dir, or at least the node_modules dir is emptied:

###############################################################################

DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'
DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'
DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'

module.js:340
    throw err;
          ^
Error: Cannot find module '/var/lib/openshift/529f8c225973ca844d000080/app-root/runtime/repo/server.js'
    at Function.Module._resolveFilename (module.js:338:15)
    at Function.Module._load (module.js:280:25)
    at Function.Module.runMain (module.js:497:10)
    at startup (node.js:119:16)
    at node.js:901:3
DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'

module.js:340
    throw err;
          ^
Error: Cannot find module 'coffee-script'
    at Function.Module._resolveFilename (module.js:338:15)
    at Function.Module._load (module.js:280:25)
    at Module.require (module.js:364:17)
    at require (module.js:380:17)
    at Object.<anonymous> (/var/lib/openshift/529f8c225973ca844d000080/app-root/runtime/repo/server.js:5:3)
    at Object.<anonymous> (/var/lib/openshift/529f8c225973ca844d000080/app-root/runtime/repo/server.js:22:4)
    at Module._compile (module.js:456:26)
    at Object.Module._extensions..js (module.js:474:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:312:12)
DEBUG: Starting child process with 'node server.js'
DEBUG: crashing child

node.js:728
        throw errnoException(process._errno, 'kill');
              ^
Error: kill ESRCH
    at errnoException (node.js:540:13)
    at process.kill (node.js:728:15)
    at null._onTimeout (/opt/rh/nodejs010/root/usr/lib/node_modules/supervisor/lib/supervisor.js:238:15)
    at Timer.listOnTimeout [as ontimeout] (timers.js:110:15)

module.js:340
    throw err;
          ^
Error: Cannot find module 'coffee-script'
    at Function.Module._resolveFilename (module.js:338:15)
    at Function.Module._load (module.js:280:25)
    at Module.require (module.js:364:17)
    at require (module.js:380:17)
    at Object.<anonymous> (/var/lib/openshift/529f8c225973ca844d000080/app-root/runtime/repo/server.js:5:3)
    at Object.<anonymous> (/var/lib/openshift/529f8c225973ca844d000080/app-root/runtime/repo/server.js:22:4)
    at Module._compile (module.js:456:26)
    at Object.Module._extensions..js (module.js:474:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:312:12)

#############################################################################

Later on I see this:
Error: ENOENT, stat '/var/lib/openshift/529f8c225973ca844d000080/app-root/runtime/repo/public/app.html'

This is a build process I run on the server (minification and joining) with brunch.io. This means that this dir must emptied.

I thought I could remedy this with this in my deploy hook (post_deploy)
But I guess that didn't help.

echo start building...
cd $OPENSHIFT_REPO_DIR
if ! gem spec sass > /dev/null 2>&1; then
  echo "Gem sass is not installed, installing it..."
  gem install sass --no-rdoc --no-ri
  echo Done installing sass
fi
export PATH=$PATH:$GEM_HOME/bin
node_modules/.bin/brunch build --production
export pub_folder=production
echo switching to $pub_folder
rsync -rtvu --delete-delay production/ public/
export pub_folder=public
echo switching back to $pub_folder
rm -rf production

echo ...done

Alex is your issue that the app never comes back up?  Or that there is a period of unavailability (should be very brief)

As Andy noted, there will always be a small window of downtime as the node process must be restarted by the supervisor when the files change.

the app comes back up, but it takes a few minutes, not what I call brief.

I appreciate that Supervisor needs some time to restart node after file changes, but as you can see in the posted logs, supervisor can't find files.

Am I the only one? Am i doing something wrong?

the app-root/repo/node_modules directory will always start out empty during each deployment, and then be populated by the build(npm) process.  Unless you have checked files into node_modules in your app repo directly and pushed them.

There are some issues with hot deploy for nodeJS that are currently being worked on:

https://bugzilla.redhat.com/show_bug.cgi?id=1043819
https://bugzilla.redhat.com/show_bug.cgi?id=1048756  (does not mention hot deploy but is caused by the same underlying problem).

However neither of those issues look like the issue you are seeing, it definitely does not normally take several minutes for the app to become available again, even without hot_deploy.  

There was another issue with the nodeJS cartridge in december when we switched from only using supervisor for hot_deploy mode, to using supervisor at all times.  Can you confirm you are still seeing this error behavior today?

Are you still having this issue?

Let me check today, but a few days ago it was still there.

Using the Node 0.10 cart', I added the hot_deploy marker, but it restarts with this:

Thu Feb 06 2014 04:09:54 GMT-0500 (EST): Stopping application 'nodeworld' ...
Thu Feb 06 2014 04:09:55 GMT-0500 (EST): Stopped Node application 'nodeworld'
Thu Feb 06 2014 04:09:55 GMT-0500 (EST): Starting application 'nodeworld' ...
/usr/bin/tail: nodejs/logs/node.log: file truncated

DEBUG: Running node-supervisor with
DEBUG:   program 'server.js'
DEBUG:   --watch '.'
DEBUG:   --ignore 'undefined'
DEBUG:   --extensions 'node|js|coffee'
DEBUG:   --exec 'node'

DEBUG: Starting child process with 'node server.js'
DEBUG: Watching directory '/var/lib/openshift/52f320195004461ec000002f/app-root/
runtime/repo' for changes.
Express & WebSocket server listening on port 8080 for IP 127.6.102.1.
World configuration loaded from database.

==> rockmongo/logs/error_log-20140206-000000-EST <==
PHP Warning:  Module 'mongo' already loaded in Unknown on line 0
[Thu Feb 06 04:10:17 2014] [notice] Digest: generating secret for digest authent
ication ...
[Thu Feb 06 04:10:17 2014] [notice] Digest: done
[Thu Feb 06 04:10:17 2014] [notice] Apache/2.2.22 (Unix) PHP/5.3.3 configured --
 resuming normal operations

==> nodejs/logs/node.log <==
GET / 200 1184ms - 5.83kb
GET / 200 61ms - 5.83kb
DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'
DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'
DEBUG: crashing child
DEBUG: Starting child process with 'node server.js'

module.js:340
    throw err;
          ^
Error: Cannot find module 'socket.io'
    at Function.Module._resolveFilename (module.js:338:15)
    at Function.Module._load (module.js:280:25)
    at Module.require (module.js:364:17)
    at require (module.js:380:17)
    at Object.<anonymous> (/var/lib/openshift/52f320195004461ec000002f/app-root/
runtime/repo/server.js:38:8)
    at Module._compile (module.js:456:26)
    at Object.Module._extensions..js (module.js:474:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:312:12)
    at Function.Module.runMain (module.js:497:10)
DEBUG: Program node server.js exited with code 8

DEBUG: Starting child process with 'node server.js'

module.js:340
    throw err;
          ^
Error: Cannot find module 'socket.io'
    at Function.Module._resolveFilename (module.js:338:15)
    at Function.Module._load (module.js:280:25)
    at Module.require (module.js:364:17)
    at require (module.js:380:17)
    at Object.<anonymous> (/var/lib/openshift/52f320195004461ec000002f/app-root/
runtime/repo/server.js:38:8)
    at Module._compile (module.js:456:26)
    at Object.Module._extensions..js (module.js:474:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:312:12)
    at Function.Module.runMain (module.js:497:10)
DEBUG: Program node server.js exited with code 8

DEBUG: Starting child process with 'node server.js'

module.js:340
    throw err;
          ^
Error: Cannot find module 'socket.io'
    at Function.Module._resolveFilename (module.js:338:15)
    at Function.Module._load (module.js:280:25)
    at Module.require (module.js:364:17)
    at require (module.js:380:17)
    at Object.<anonymous> (/var/lib/openshift/52f320195004461ec000002f/app-root/
runtime/repo/server.js:38:8)
    at Module._compile (module.js:456:26)
    at Object.Module._extensions..js (module.js:474:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:312:12)
    at Function.Module.runMain (module.js:497:10)
DEBUG: Program node server.js exited with code 8

DEBUG: Starting child process with 'node server.js'

And then it starts normally and works.

I need supervisor to --watch only my 'server.js' file. The other files are supposed to be changed and reloaded during runtime, without restarting the server. I do this, when testing on my machine.

regarding comment 9, can you open a separate bug/RFE for allowing supervisor to only watch server.js?

(In reply to Ben Parees from comment #10)
> regarding comment 9, can you open a separate bug/RFE for allowing supervisor
> to only watch server.js?

It would be my pleasure.

You can now use the 'OPENSHIFT_NODEJS_WATCH' environment variable to change what the supervisor should watch for changes. Note that the supervisor is currently limited to watch only whole directories, not just files.

There is a Trello card to change the current default behavior (iow watching the whole repo dir) and restrict watching to just single file that is touched after each deploy (in hot_deploy mode).

https://trello.com/c/Z0dieVkU/156-1-add-support-for-pseudo-hot-deploy-into-nodejs-npm-devexp

This should be part of the next release.