CentOS, Node.js, init.d, ENOENT, Can't open or write to log files on system reboot when app started automatically

Question

I have a Node.js service script that must be executed when my CentOS 7 server is booted. I utilized an init.d template to create a startup Daemon. The init.d script works perfectly if I am logged into the server as root and execute the script manually in the terminal using:

sudo /etc/init.d/ServerStatusService start(stop,restart,status)

The Node script executes and does what it does without issue, which includes writing to some log files in the log folder within the application directory.

The issue I have is that when the server is restarted the init.d script executes just fine and it starts the Node script as well, only the Node script then errors out with an uncaught exception of type 'ENOENT' stating it cannot open the log file it is to write to.

From everything I have read all init.d scripts execute as root at startup so I would expect it to work without issue just like it does when I manually start the init.d script using sudo in the terminal.

For the life of me I cannot figure out what the deal is. I assume its a permission thing or environment thing at system start up that is different than running sudo in the terminal.

I also ran the init.d script using the following options to duplicate the state of the machine at startup and it fails just like at boot up.

env -i LANG="$LANG" PATH="$PATH" TERM="$TERM" /etc/init.d/ServerStatusService start

My init.d script

#!/bin/sh

NODE_ENV="staging"
PORT="8088"
APP_DIR="/var/www/ServerStatusClientn"
NODE_APP="serverStatusService.js"
CONFIG_DIR="$APP_DIR"
PID_DIR="$APP_DIR/pid"
PID_FILE="$PID_DIR/app.pid"
LOG_DIR="$APP_DIR/logs"
LOG_FILE="$LOG_DIR/app.log"
NODE_EXEC=$(which node)

USAGE="Usage: $0 {start|stop|restart|status} [--force]"
FORCE_OP=false

pid_file_exists() {
    [ -f "$PID_FILE" ]
}

get_pid() {
    echo "$(cat "$PID_FILE")"
}

is_running() {
    PID=$(get_pid)
    ! [ -z "$(ps aux | awk '{print $2}' | grep "^$PID$")" ]
}

start_it() {
    mkdir -p "$PID_DIR"
    mkdir -p "$LOG_DIR"

    echo "Starting node app ..."
    PORT="$PORT" NODE_ENV="$NODE_ENV" NODE_CONFIG_DIR="$CONFIG_DIR" $NODE_EXEC "$APP_DIR/$NODE_APP"  1>"$LOG_FILE" 2>&1 &
    echo $! > "$PID_FILE"
    echo "Node app started with pid $!"
}

stop_process() {
    PID=$(get_pid)
    echo "Killing process $PID"
    kill $PID
}

remove_pid_file() {
    echo "Removing pid file"
    rm -f "$PID_FILE"
}

start_app() {
    if pid_file_exists
    then
        if is_running
        then
            PID=$(get_pid)
            echo "Node app already running with pid $PID"
            exit 1
        else
            echo "Node app stopped, but pid file exists"
            if [ $FORCE_OP = true ]
            then
                echo "Forcing start anyways"
                remove_pid_file
                start_it
            fi
        fi
    else
        start_it
    fi
}

stop_app() {
    if pid_file_exists
    then
        if is_running
        then
            echo "Stopping node app ..."
            stop_process
            remove_pid_file
            echo "Node app stopped"
        else
            echo "Node app already stopped, but pid file exists"
            if [ $FORCE_OP = true ]
            then
                echo "Forcing stop anyways ..."
                remove_pid_file
                echo "Node app stopped"
            else
                exit 1
            fi
        fi
    else
        echo "Node app already stopped, pid file does not exist"
        exit 1
    fi
}

status_app() {
    if pid_file_exists
    then
        if is_running
        then
            PID=$(get_pid)
            echo "Node app running with pid $PID"
        else
            echo "Node app stopped, but pid file exists"
        fi
    else
        echo "Node app stopped"
    fi
}

case "$2" in
    --force)
        FORCE_OP=true
    ;;

    "")
    ;;

    *)
        echo $USAGE
        exit 1
    ;;
esac

case "$1" in
    start)
        start_app
    ;;

    stop)
        stop_app
    ;;

    restart)
        stop_app
        start_app
    ;;

    status)
        status_app
    ;;

    *)
        echo $USAGE
        exit 1
    ;;
esac

Error logs

error: uncaughtException: ENOENT, open 'logs/mediaServerStatus-debug.log' date=Mon Feb 09 2015 11:03:00 GMT-0700 (MST), pid=6329, uid=0, gid=0, cwd=/, execPath=/usr/bin/node, version=v0.10.33, argv=[/usr/bin/node, /var/www/MediaServerStatusService/service.js], rss=40230912, heapTotal=28055552, heapUsed=14903704, loadavg=[0.064453125, 0.18310546875, 0.181640625], uptime=6808.08772411, trace=[], stack=[Error: ENOENT, open 'logs/mediaServerStatus-debug.log']
error: uncaughtException: ENOENT, open 'logs/mediaServerStatus-debug.log' date=Mon Feb 09 2015 11:03:00 GMT-0700 (MST), pid=6329, uid=0, gid=0, cwd=/, execPath=/usr/bin/node, version=v0.10.33, argv=[/usr/bin/node, /var/www/MediaServerStatusService/service.js], rss=40230912, heapTotal=28055552, heapUsed=15008752, loadavg=[0.064453125, 0.18310546875, 0.181640625], uptime=6808.090709357, trace=[], stack=[Error: ENOENT, open 'logs/mediaServerStatus-debug.log']

Logging with Winston

var winston = require('winston'),
config = require('../config/config');
winston.emitErrs = true;

var debug = new winston.Logger({
    transports: [
        new winston.transports.Console({
            level: 'debug',
            handleExceptions: true,
            json: false,
            colorize: true
        })
    ]
});

if(config.logging.debugToFile){
    debug.add(
        winston.transports.File,
        {
            name: 'debug-file',
            level: 'debug',
            filename: config.logging.debug,
            handleExceptions: true,
            json: true,
            maxsize: 5242880, //5MB
            maxFiles: 5,
            colorize: false
        }
    );
}

var info = new winston.Logger({
    transports: [
        new winston.transports.Console({
            level: 'info',
            handleExceptions: true,
            json: false,
            colorize: true
        })
    ]
});

var warn = new winston.Logger({
    transports: [
        new winston.transports.File({
            name: 'warn-file',
            level: 'warn',
            filename: config.logging.warn,
            handleExceptions: true,
            json: true,
            maxsize: 5242880, //5MB
            maxFiles: 5,
            colorize: false
        }),
        new winston.transports.Console({
            level: 'warn',
            handleExceptions: true,
            json: false,
            colorize: true
        })
    ]
});

var error = new winston.Logger({
    transports: [
        new winston.transports.File({
            name: 'error-file',
            level: 'error',
            filename: config.logging.error,
            handleExceptions: true,
            json: true,
            maxsize: 5242880, //5MB
            maxFiles: 5,
            colorize: false
        }),
        new winston.transports.Console({
            level: 'error',
            handleExceptions: true,
            json: false,
            colorize: true
        })
    ]
});

var loggers = {
    debug: function(msg, callback){
        debug.debug(msg, callback);
    },
    info: function(msg, callback){
        info.info(msg, callback);
    },
    warn: function(msg, callback){
        warn.warn(msg, callback);
    },
    error: function(msg, callback){
        error.error(msg, callback);
    },
    log: function(level,msg, callback){
        var lvl = exports[level];
        lvl(msg, callback);
    }
};

// Logging
module.exports = loggers;

Config holding log file paths

logging: {
    debugToFile: true,
    debug: './logs/mediaServerStatus-debug.log',
    info: './logs/mediaServerStatus-info.log',
    warn: './logs/mediaServerStatus-warn.log',
    error: './logs/mediaServerStatus-error.log'
}

Here are the actual errors recorded in the init.d log. If it is an issue with the init.d executing the script from the path of node using an absolute path, how does one execute the script using init.d but relative to the application's root directory so that everything is relative to the app not node? — Schleichermann, Feb 09 '15 at 18:04

score 3 · Accepted Answer · answered Feb 09 '15 at 18:25

3

Init.d script starts the Node script from the node executable's path.

You need to specify the script's directory by __dirname to make the paths absolute.

logging: {
    debugToFile: true,
    debug: path.join(__dirname, 'logs/mediaServerStatus-debug.log'),
    info:  path.join(__dirname, 'logs/mediaServerStatus-info.log'),
    warn:  path.join(__dirname, 'logs/mediaServerStatus-warn.log'),
    error: path.join(__dirname, 'logs/mediaServerStatus-error.log'),
}

Be sure to var path = require('path'); before it. (it's a native module, doesn't need installing)

answered Feb 09 '15 at 18:25

laggingreflex

32,948
35
141
196

Wow! Knowing that a lot of applications websites, services, API's and the like, built on Node, are going to need to be restarted on servers at boot up and will have to be done using something like init.d, you would think Node would handle this internally instead of forcing me to add __dirname to all my paths. – Schleichermann Feb 09 '15 at 18:31
laggingreflex, do I need to do this to all my 'require' statements that are not node_modules? – Schleichermann Feb 09 '15 at 18:32
so a require like var path = require('path') pulls from either Node core or the node_modules folder so they are imported just fine. I was wondering if local project files being required with a relative path would also have to have __dirname added to them, a require like var logger = require('./logger'); for example, would it need to be var logger = require(__dirname + '/logger'); or does Node handle that without issue? – Schleichermann Feb 09 '15 at 18:39
[`require`](http://nodejs.org/api/modules.html) does workout relative paths itself without issues, funnily. So no, you don't have to change anything in `require` syntax. – laggingreflex Feb 09 '15 at 18:42
Excellent, I really appreciate the assistance. – Schleichermann Feb 09 '15 at 18:44

CentOS, Node.js, init.d, ENOENT, Can't open or write to log files on system reboot when app started automatically

1 Answers1