diff --git a/box.js b/box.js index d8de086dc..927bb0a26 100755 --- a/box.js +++ b/box.js @@ -13,11 +13,13 @@ let async = require('async'), const NOOP_CALLBACK = function () { }; function setupLogging(callback) { + if (process.env.BOX_ENV === 'test') return callback(); + fs.open(paths.BOX_LOG_FILE, 'a', function (error, fd) { if (error) return callback(error); require('debug').log = function (...args) { - fs.appendFileSync(fd, (args.length ? util.format(...args) : '') + '\n'); + fs.appendFileSync(fd, util.format(...args) + '\n'); }; callback(); diff --git a/src/tasks.js b/src/tasks.js index 780fc4283..cc37f8667 100644 --- a/src/tasks.js +++ b/src/tasks.js @@ -43,7 +43,6 @@ let assert = require('assert'), child_process = require('child_process'), debug = require('debug')('box:tasks'), paths = require('./paths.js'), - safe = require('safetydance'), spawn = require('child_process').spawn, split = require('split'), taskdb = require('./taskdb.js'), @@ -138,17 +137,12 @@ function startTask(taskId, options, callback) { assert.strictEqual(typeof callback, 'function'); const logFile = options.logFile || `${paths.TASKS_LOG_DIR}/${taskId}.log`; - let fd = safe.fs.openSync(logFile, 'a'); // will autoclose. append is for apptask logs - if (!fd) { - debug(`startTask: unable to get log filedescriptor ${safe.error.message}`); - return callback(new BoxError(BoxError.FS_ERROR, safe.error)); - } - debug(`startTask - starting task ${taskId}. logs at ${logFile}`); let killTimerId = null, timedOut = false; - gTasks[taskId] = child_process.fork(`${__dirname}/taskworker.js`, [ taskId ], { stdio: [ 'pipe', fd, fd, 'ipc' ]}); // fork requires ipc + const env = Object.assign({ DEBUG: 'box:*' }, process.env); // when called from npm test, DEBUG is not set + gTasks[taskId] = child_process.fork(`${__dirname}/taskworker.js`, [ taskId, logFile ], { env }); // fork requires ipc gTasks[taskId].once('exit', function (code, signal) { debug(`startTask: ${taskId} completed with code ${code} and signal ${signal}`); diff --git a/src/taskworker.js b/src/taskworker.js index cef89cc60..1866dcaa7 100755 --- a/src/taskworker.js +++ b/src/taskworker.js @@ -1,19 +1,17 @@ 'use strict'; var apptask = require('./apptask.js'), - assert = require('assert'), async = require('async'), backups = require('./backups.js'), database = require('./database.js'), - debug = require('debug')('box:taskworker'), domains = require('./domains.js'), externalLdap = require('./externalldap.js'), + fs = require('fs'), reverseProxy = require('./reverseproxy.js'), settings = require('./settings.js'), tasks = require('./tasks.js'), - updater = require('./updater.js'); - -const NOOP_CALLBACK = function (error) { if (error) debug(error); }; + updater = require('./updater.js'), + util = require('util'); const TASKS = { // indexed by task type app: apptask.run, @@ -26,31 +24,47 @@ const TASKS = { // indexed by task type _identity: (arg, progressCallback, callback) => callback(null, arg), _error: (arg, progressCallback, callback) => callback(new Error(`Failed for arg: ${arg}`)), - _crash: (arg) => { throw new Error(`Crashing for arg: ${arg}`); }, + _crash: (arg) => { throw new Error(`Crashing for arg: ${arg}`); }, // the test looks for this debug string in the log file _sleep: (arg) => setTimeout(process.exit, arg) }; -process.on('SIGTERM', function () { - process.exit(0); -}); +if (process.argv.length !== 4) { + console.error('Pass the taskid and logfile as argument'); + process.exit(1); +} -assert.strictEqual(process.argv.length, 3, 'Pass the taskid as argument'); const taskId = process.argv[2]; +const logFile = process.argv[3]; -function initialize(callback) { - async.series([ - database.initialize, - settings.initCache - ], callback); +function setupLogging(callback) { + fs.open(logFile, 'a', function (error, fd) { + if (error) return callback(error); + + require('debug').log = function (...args) { + fs.appendFileSync(fd, util.format(...args) + '\n'); + }; + + callback(); + }); } // Main process starts here const startTime = new Date(); -debug(`Starting task ${taskId}`); -initialize(function (error) { +async.series([ + setupLogging, + database.initialize, + settings.initCache +], function (error) { if (error) return process.exit(50); + const debug = require('debug')('box:taskworker'); // require this here so that logging handler is already setup + const NOOP_CALLBACK = function (error) { if (error) debug(error); }; + + process.on('SIGTERM', () => process.exit(0)); + + debug(`Starting task ${taskId}. Logs are at ${logFile}`); + tasks.get(taskId, function (error, task) { if (error) return process.exit(50); @@ -67,6 +81,11 @@ initialize(function (error) { tasks.setCompleted(taskId, progress, () => process.exit(error ? 50 : 0)); }; - TASKS[task.type].apply(null, task.args.concat(progressCallback).concat(resultCallback)); + try { + TASKS[task.type].apply(null, task.args.concat(progressCallback).concat(resultCallback)); + } catch (error) { + debug('Uncaught exception in task', error); + process.exit(1); // do not call setCompleted() intentionally. the task code must be resilient enough to handle it + } }); }); diff --git a/src/test/apptask-test.js b/src/test/apptask-test.js index 97887f866..b489b73f6 100644 --- a/src/test/apptask-test.js +++ b/src/test/apptask-test.js @@ -5,8 +5,7 @@ 'use strict'; -var addons = require('../addons.js'), - appdb = require('../appdb.js'), +var appdb = require('../appdb.js'), apps = require('../apps.js'), apptask = require('../apptask.js'), async = require('async'),