diff --git a/public/templates/admin/logger.tpl b/public/templates/admin/logger.tpl index 969647f820..83f569010b 100644 --- a/public/templates/admin/logger.tpl +++ b/public/templates/admin/logger.tpl @@ -5,9 +5,13 @@

- By enabling the check boxes, you will receive logs to standard output. If you specify a path, logs will then be saved to a file instead. HTTP logging is useful for collecting statistics about who and when people access your forum. Socket.io logging, in combination with redis-cli monitor, can be very helpful for learning NodeBB's internals. + By enabling the check boxes, you will receive logs to your terminal. If you specify a path, logs will then be saved to a file instead. HTTP logging is useful for collecting statistics about who, when, and what people access on your forum. In addition to logging HTTP requests, we can also log socket.io events. Socket.io logging, in combination with redis-cli monitor, can be very helpful for learning NodeBB's internals.


+

+ Simply check/uncheck the logging settings to enable or disable logging on the fly. No restart needed. +

+
@@ -17,24 +21,19 @@

- - -
-
-
-

- - + + +


- +
diff --git a/src/logger.js b/src/logger.js new file mode 100644 index 0000000000..37f5aab35b --- /dev/null +++ b/src/logger.js @@ -0,0 +1,198 @@ +/* + * Logger module: ability to dynamically turn on/off logging for http requests & socket.io events + */ + +var fs = require('fs'), + express = require('express'), + winston = require('winston'), + util = require('util'), + socketio = require('socket.io'), + meta = require('./meta.js'); + +var opts = { + /* + * state used by Logger + */ + express : { + app : {}, + set : 0, + ofn : null, + }, + streams : { + log : { f : process.stdout }, + } +}; + +(function(Logger) { + + + Logger.init = function(app) { + opts.express.app = app; + /* Open log file stream & initialize express logging if meta.config.logger* variables are set */ + Logger.setup(); + } + + Logger.setup = function() { + Logger.setup_one('loggerPath', meta.config.loggerPath); + } + + Logger.setup_one = function(key,value) { + /* + * 1. Open the logger stream: stdout or file + * 2. Re-initialize the express logger hijack + */ + switch(key) { + case 'loggerPath': { + Logger.setup_one_log(value); + Logger.express_open(); + } + default: return; + } + } + + Logger.setup_one_log = function(value) { + + if(meta.config.loggerStatus > 0 || meta.config.loggerIOStatus) { + var stream = Logger.open(value); + if(stream) opts.streams.log.f = stream; + else opts.streams.log.f = process.stdout; + } + else { + Logger.close(opts.streams.log); + } + + } + + Logger.open = function(value) { + + /* Open the streams to log to: either a path or stdout */ + var stream; + if(value) + stream = fs.createWriteStream(value, {flags: 'a'}); + else + stream = process.stdout; + + return stream; + } + + Logger.close = function(stream) { + if(stream.f != process.stdout && stream.f != null) stream.end(); + stream.f = null; + } + + Logger.monitorConfig = function(socket, data) { + /* + * This monitor's when a user clicks "save" in the Logger section of the admin panel + */ + Logger.setup_one(data.key,data.value); + Logger.io_close(socket); + Logger.io(socket); + } + + Logger.express_open = function() { + if(opts.express.set != 1) { + opts.express.set = 1; + opts.express.app.use(Logger.expressLogger); + } + /* + * Always initialize "ofn" (original function) with the original logger function + */ + opts.express.ofn = express.logger({stream : opts.streams.log.f}); + } + + Logger.expressLogger = function(req,res,next) { + /* + * The new express.logger + * + * This hijack allows us to turn logger on/off dynamically within express + */ + if(meta.config.loggerStatus > 0) { + return opts.express.ofn(req,res,next); + } + else { + return next() + } + } + + Logger.prepare_io_string = function(_type, _uid, _args) { + /* + * This prepares the output string for intercepted socket.io events + * + * The format is: io: + */ + try { + return 'io: '+_uid+' '+_type+' '+util.inspect(Array.prototype.slice.call(_args))+'\n'; + } catch(err) { + winston.info("Logger.prepare_io_string: Failed",err) + return "error"; + } + } + + Logger.io_close = function(socket) { + /* + * Restore all hijacked sockets to their original emit/on functions + */ + var clients = socket.io.sockets.clients(); + for(var v in clients) { + var client = clients[v]; + + if(client.oEmit != client.emit) + client.emit = client.oEmit; + + if(client.$oEmit != client.$emit) + client.$emit = client.$oEmit; + } + } + + Logger.io = function(socket) { + if(socket == undefined && socket.io.sockets == undefined) { + return; + } + + var clients = socket.io.sockets.clients(); + for(var v in clients) { + var client = clients[v]; + Logger.io_one(client,client.state.user.uid); + } + } + + Logger.io_one = function(socket,uid) { + /* + * This function replaces a socket's .emit/.on functions in order to intercept events + */ + if(socket != undefined && meta.config.loggerIOStatus > 0) { + + (function() { + // courtesy of: http://stackoverflow.com/a/9674248 + var user = uid + if(!user) user = "?" + socket.oEmit = socket.emit; + var emit = socket.emit; + socket.emit = function() { + if(opts.streams.log.f != null) { + opts.streams.log.f.write(Logger.prepare_io_string("emit",uid,arguments)); + } + try { + emit.apply(socket, arguments); + } catch(err) { + winston.info("Logger.io_one: emit.apply: Failed", err); + } + }; + socket.$oEmit = socket.$emit; + var $emit = socket.$emit; + socket.$emit = function() { + + if(opts.streams.log.f != null) { + opts.streams.log.f.write(Logger.prepare_io_string("on",uid,arguments)); + } + try { + $emit.apply(socket, arguments); + } catch(err) { + winston.info("Logger.io_one: $emit.apply: Failed", err); + } + }; + })(); + } + } + +}(exports)); diff --git a/src/webserver.js b/src/webserver.js index b11c01e7c8..f06f602b12 100644 --- a/src/webserver.js +++ b/src/webserver.js @@ -24,7 +24,8 @@ var express = require('express'), plugins = require('./plugins'), nconf = require('nconf'), winston = require('winston'), - validator = require('validator'); + validator = require('validator'), + logger = require('./logger.js'); (function (app) { var templates = null, @@ -80,20 +81,7 @@ var express = require('express'), // Pre-router middlewares app.use(express.compress()); - if(nconf.get("express:logger") == true || meta.config.loggerStatus > 0) { - /* - * HTTP request logging is enabled - */ - var loggerObj = {}; - if(meta.config.loggerPath) { - loggerObj.stream = fs.createWriteStream(meta.config.loggerPath, {flags: 'a'}); - } - else { - loggerObj.stream = process.stdout; - } - meta.config.loggerStream = loggerObj.stream; - app.use(express.logger(loggerObj)); - } + logger.init(app); app.use(express.favicon(path.join(__dirname, '../', 'public', 'favicon.ico'))); app.use(require('less-middleware')({ diff --git a/src/websockets.js b/src/websockets.js index 6f2841650a..76336dd99c 100644 --- a/src/websockets.js +++ b/src/websockets.js @@ -17,6 +17,7 @@ var cookie = require('cookie'), RedisStoreLib = require('connect-redis')(express), RDB = require('./redis'), util = require('util'), + logger = require('./logger.js'), fs = require('fs') RedisStore = new RedisStoreLib({ client: RDB, @@ -67,50 +68,15 @@ module.exports.init = function(io) { userSockets[uid] = userSockets[uid] || []; userSockets[uid].push(socket); - - if(meta.config.loggerIOStatus > 0) { - var _prepare_loggerIO_string = function(_type, _uid, _args) { - try { - return 'io: '+_uid+' '+_type+' '+util.inspect(Array.prototype.slice.call(_args))+'\n'; - } catch(err) { - winston.err(err) - } + /* Need to save some state for the logger & maybe some other modules later on */ + socket.state = { + user : { + uid : uid } + }; - - /* - * socket.io emit/on logging is enabled - */ - if(!meta.config.loggerIOStream) { - var loggerObj = {}; - if(meta.config.loggerIOPath) { - var actual_path = meta.config.loggerIOPath; - if(meta.config.loggerIOPath == meta.config.loggerPath) { actual_path = actual_path + ".io.log"; } - loggerObj.stream = fs.createWriteStream(actual_path, {flags: 'a'}); - } - else { - loggerObj.stream = process.stdout; - } - meta.config.loggerIOStream = loggerObj.stream; - } - - - (function() { - // courtesy of: http://stackoverflow.com/a/9674248 - var user = uid - if(!user) user = "?" - var emit = socket.emit; - socket.emit = function() { - meta.config.loggerIOStream.write(_prepare_loggerIO_string("emit",uid,arguments)); - emit.apply(socket, arguments); - }; - var $emit = socket.$emit; - socket.$emit = function() { - meta.config.loggerIOStream.write(_prepare_loggerIO_string("on",uid,arguments)); - $emit.apply(socket, arguments); - }; - })(); - } + /* If meta.config.loggerIOStatus > 0, logger.io_one will hook into this socket */ + logger.io_one(socket,uid); if (uid) { @@ -679,6 +645,8 @@ module.exports.init = function(io) { if (!err) socket.emit('api:config.set', { status: 'ok' }); + /* Another hook, for my (adarqui's) logger module */ + logger.monitorConfig(this, data); }); });