diff --git a/lib/log.js b/lib/log.js new file mode 100644 index 000000000..7170fd0e2 --- /dev/null +++ b/lib/log.js @@ -0,0 +1,99 @@ +/*jshint esversion: 6 */ +var Store = require("../storage/file"); + +var Logger = module.exports; + +/* Every line in the log should contain: + * timestamp + * public key of initiator + * the action + * the event's tag +*/ +var messageTemplate = function (type, time, tag, info) { + return JSON.stringify([type.toUpperCase(), time, tag, info]); +}; + +var write = function (ctx, content) { + ctx.store.log(ctx.channelName, content); +}; + +// various degrees of logging +const logLevels = ['silly', 'debug', 'verbose', 'feedback', 'info', 'warn', 'error']; + +var handlers = { + silly: function (ctx, time, tag, info) { + console.log('[SILLY]', time, tag, info); + }, + debug: function (ctx, time, tag, info) { + console.log('[DEBUG]', time, tag, info); + }, + verbose: function (ctx, time, tag, info) { + console.log('[VERBOSE]', time, tag, info); + }, + feedback: function (ctx, time, tag, info) { + console.log('[FEEDBACK]', time, tag, info); + }, + info: function (ctx, time, tag, info) { + console.info('[INFO]', time, tag, info); + }, + warn: function (ctx, time, tag, info) { + console.warn('[WARN]', time, tag, info); + }, + error: function (ctx, time, tag, info) { + console.error('[ERROR]', time, tag, info); + } +}; + +var createLogType = function (ctx, type) { + return function (tag, info) { + var time = new Date().toISOString(); + var content; + try { + content = messageTemplate(type, time, tag, info); + } catch (e) { + return; + } + + if (ctx.logToStdout && typeof(handlers[type]) === 'function') { + handlers[type](ctx, time, tag, info); + } + write(ctx, content); + }; +}; + +// Log.verbose('THING', x); +Logger.create = function (config, cb) { + if (!config.logPath) { + // XXX don't crash, print that you won't log to file + throw new Error("Logger: Expected filePath"); + } + + /* config: { + filePath: '???', + logLevel: 'silly', + } */ + + var date = new Date(); + var launchTime = ('' + date.getUTCFullYear()).slice(-2) + date.toISOString(); + + Store.create({ + filePath: config.logPath, + }, function (store) { + var ctx = { + store: store, + channelName: launchTime, + logFeedback: Boolean(config.logFeedback), + // TODO respect configured log settings + logLevel: logLevels.indexOf(config.logLevel), // 0 for silly, 1 for debug + }; + + var log = {}; + logLevels.forEach(function (type) { + log[type] = createLogType(ctx, type); + }); + + cb(Object.freeze(log)); + }); +}; + + diff --git a/rpc.js b/rpc.js index 62bc3e274..9993f3a19 100644 --- a/rpc.js +++ b/rpc.js @@ -27,6 +27,8 @@ var DEFAULT_LIMIT = 50 * 1024 * 1024; var SESSION_EXPIRATION_TIME = 60 * 1000; var SUPPRESS_RPC_ERRORS = false; +var Log; + var WARN = function (e, output) { if (!SUPPRESS_RPC_ERRORS && e && output) { console.error(new Date().toISOString() + ' [' + String(e) + ']', output); @@ -199,8 +201,7 @@ var checkSignature = function (signedMsg, signature, publicKey) { try { signedBuffer = Nacl.util.decodeUTF8(signedMsg); } catch (e) { - console.log('invalid signedBuffer'); // FIXME logging - console.log(signedMsg); + Log.error('INVALID_SIGNED_BUFFER', signedMsg); return null; } @@ -217,8 +218,7 @@ var checkSignature = function (signedMsg, signature, publicKey) { } if (pubBuffer.length !== 32) { - console.log('public key length: ' + pubBuffer.length); // FIXME logging - console.log(publicKey); + Log.error('PUBLIC_KEY_LENGTH', publicKey); return false; } @@ -269,10 +269,10 @@ var loadUserPins = function (Env, publicKey, cb) { } break; default: - WARN('invalid message read from store', msg); // FIXME logging + Log.warn('INVALID_STORED_MESSAGE', msg); } } catch (e) { - WARN('invalid message read from store', e); // FIXME logging + Log.warn('STORED_PARSE_ERROR', e); } }, function () { // no more messages @@ -969,8 +969,11 @@ var upload_cancel = function (Env, publicKey, fileSize, cb) { var path = makeFilePath(paths.staging, publicKey); if (!path) { - console.log(paths.staging, publicKey); // FIXME logging - console.log(path); + Log.error('UPLOAD_CANCEL_INVALID_PATH', { + staging: paths.staging, + key: publicKey, + path: path, + }); return void cb('NO_FILE'); } @@ -1313,7 +1316,7 @@ var validateLoginBlock = function (Env, publicKey, signature, block, cb) { try { u8_signature = Nacl.util.decodeBase64(signature); } catch (e) { - console.error(e); // FIXME logging + Log.error('INVALID_BLOCK_SIGNATURE', e); return void cb('E_INVALID_SIGNATURE'); } @@ -1414,7 +1417,6 @@ var removeLoginBlock = function (Env, msg, cb) { var block = Nacl.util.decodeUTF8('DELETE_BLOCK'); // clients and the server will have to agree on this constant // FIXME deletion - // FIXME logging validateLoginBlock(Env, publicKey, signature, block, function (e /*::, validatedBlock */) { if (e) { return void cb(e); } // derive the filepath @@ -1524,16 +1526,7 @@ var getActiveSessions = function (Env, ctx, cb) { }; var adminCommand = function (Env, ctx, publicKey, config, data, cb) { - var admins = []; - try { - admins = (config.adminKeys || []).map(function (k) { - k = k.replace(/\/+$/, ''); - var s = k.split('/'); - return s[s.length-1]; - }); - } catch (e) { - console.error("Can't parse admin keys. Please update or fix your config.js file!"); // FIXME logging - } + var admins = Env.admins; if (admins.indexOf(publicKey) === -1) { return void cb("FORBIDDEN"); } @@ -1631,8 +1624,10 @@ RPC.create = function ( debuggable /*:(string, T)=>T*/, cb /*:(?Error, ?Function)=>void*/ ) { + Log = config.log; + // load pin-store... - console.log('loading rpc module...'); // FIXME logging + Log.silly('LOADING RPC MODULE'); if (config.suppressRPCErrors) { SUPPRESS_RPC_ERRORS = true; } @@ -1649,8 +1644,20 @@ RPC.create = function ( pinStore: (undefined /*:any*/), pinnedPads: {}, evPinnedPadsReady: mkEvent(true), - limits: {} + limits: {}, + admins: [], }; + + try { + Env.admins = (config.adminKeys || []).map(function (k) { + k = k.replace(/\/+$/, ''); + var s = k.split('/'); + return s[s.length-1]; + }); + } catch (e) { + console.error("Can't parse admin keys. Please update or fix your config.js file!"); + } + debuggable('rpc_env', Env); var Sessions = Env.Sessions; @@ -1718,7 +1725,7 @@ RPC.create = function ( respond(e, [null, isNew, null]); }); default: - console.error("unsupported!"); // FIXME logging + Log.warn("UNSUPPORTED_RPC_CALL", msg); return respond('UNSUPPORTED_RPC_CALL', msg); } }; @@ -1727,13 +1734,14 @@ RPC.create = function ( if (!Env.msgStore) { Env.msgStore = ctx.store; } if (!Array.isArray(data)) { - return void respond('INVALID_ARG_FORMAT'); // FIXME logging + Log.debug('INVALID_ARG_FORMET', data); + return void respond('INVALID_ARG_FORMAT'); } if (!data.length) { return void respond("INSUFFICIENT_ARGS"); } else if (data.length !== 1) { - console.log('[UNEXPECTED_ARGUMENTS_LENGTH] %s', data.length); // FIXME logging + Log.debug('UNEXPECTED_ARGUMENTS_LENGTH', data); } var msg = data[0].slice(0); @@ -1753,7 +1761,7 @@ RPC.create = function ( if (publicKey) { getSession(Sessions, publicKey); } else { - console.log("No public key"); // FIXME logging + Log.debug("NO_PUBLIC_KEY_PROVIDED", publicKey); } var cookie = msg[0]; @@ -1775,7 +1783,7 @@ RPC.create = function ( return void respond("INVALID_SIGNATURE_OR_PUBLIC_KEY"); } } else if (msg[1] !== 'UPLOAD') { - console.error("INVALID_RPC CALL:", msg[1]); // FIXME logging + Log.warn('INVALID_RPC_CALL', msg[1]); return void respond("INVALID_RPC_CALL"); } @@ -1804,7 +1812,7 @@ RPC.create = function ( } var handleMessage = function () { - if (config.logRPC) { console.log(msg[0]); } + Log.silly('LOG_RPC', msg[0]); switch (msg[0]) { case 'COOKIE': return void Respond(void 0); case 'RESET': diff --git a/server.js b/server.js index 65627dc07..07cfd99dd 100644 --- a/server.js +++ b/server.js @@ -104,7 +104,7 @@ if (!config.logFeedback) { return; } const logFeedback = function (url) { url.replace(/\?(.*?)=/, function (all, fb) { - console.log('[FEEDBACK] %s', fb); + config.log.feedback(fb, ''); }); }; @@ -254,6 +254,13 @@ var historyKeeper; // Initialize tasks, then rpc, then store, then history keeper and then start the server var nt = nThen(function (w) { + // set up logger + var Logger = require("./lib/log"); + console.log("Loading logging module"); + Logger.create(config, w(function (_log) { + config.log = _log; + })); +}).nThen(function (w) { var Tasks = require("./storage/tasks"); console.log("loading task scheduler"); Tasks.create(config, w(function (e, tasks) { diff --git a/storage/file.js b/storage/file.js index 46ae366a6..59256224a 100644 --- a/storage/file.js +++ b/storage/file.js @@ -468,6 +468,9 @@ module.exports.create = function ( if (!isValidChannelId(channelName)) { return void cb(new Error('EINVAL')); } clearChannel(env, channelName, cb); }, + log: function (channelName, content, cb) { + message(env, channelName, content, cb); + }, shutdown: function () { clearInterval(it); }