Close #30: Add winston logging library with multiple log levels

frontend/webinterface.js

@@ -39,6 +39,11 @@ module.exports = Module.extend({
         webinterface.set('config', self.config);
         webinterface.set('app', self.app);
 
+        webinterface.use(function (req, res, next) {
+            next();
+            self.app.logger.info('%s - %s %s HTTP/%s', req.ip, req.method, req.path, req.httpVersion);
+        });
+
         webinterface.use(favicon(path.join(__dirname, '../build/public/images/favicon.ico')));
         webinterface.use(compression());
         webinterface.use(errorHandler());
@@ -58,7 +63,7 @@ module.exports = Module.extend({
 
         self.server = http.createServer(webinterface).listen(webinterface.get('port'), function(){
             self.io = require('socket.io').listen(self.server, { log: false });
-            console.log('Express and Websocket server listening on port ' + webinterface.get('port'));
+            self.app.logger.info('server listening on port ' + webinterface.get('port'));
 
             self.app.modules.forEach(function (module) {
                 module.on('change', function (data) {

lib/App.js

@@ -3,6 +3,7 @@
 var EventEmitter = require('eventemitter2').EventEmitter2,
     crypto = require('crypto'),
     _ = require('lodash'),
+    Logger = require('./Logger'),
     App;
 
 App = function (config) {
@@ -16,6 +17,7 @@ App = function (config) {
     this.modules = [];
     this.views = [];
     this.title = config.title || 'Miner-Dashboard';
+    this.logger = new Logger(config.logs);
 
     (config.modules || []).forEach(function (moduleConfig) {
         var sha1sum,

lib/Logger.js

@@ -0,0 +1,17 @@
+'use strict';
+
+var _ = require('lodash'),
+    winston = require('winston');
+
+module.exports = function (options) {
+    var defaults = {
+        level: 'info'
+    };
+
+    options = _.defaults(options || {}, defaults);
+    if (!options.transports) {
+        options.transports = [ new (winston.transports.Console)({ level: options.level, timestamp: true }) ];
+    }
+
+    return new (winston.Logger)(options);
+};

lib/modules/markets/bitcoincharts.js

@@ -43,8 +43,10 @@ module.exports = Module.extend({
             json: true
         }, function (err, res) {
             if (err) {
+                self.app.logger.info('%s - error fetching markets from bitcoincharts.com', self.id, err);
                 return;
             }
+            self.app.logger.debug('%s - fetched markets from bitcoincharts.com', self.id, JSON.stringify(res.statusCode), JSON.stringify(res.body));
             if (res.statusCode !== 200) {
                 return;
             }
@@ -54,7 +56,7 @@ module.exports = Module.extend({
             })[0];
 
             if (market) {
-                self.set(market);
+                self.set(_.clone(market));
             }
         });
     },

lib/modules/miners/bfgminer.js

@@ -35,6 +35,7 @@ module.exports = Module.extend({
     update: function () {
         var self = this,
             reportError = function (err) {
+                self.app.logger.info('%s - error fetching data', self.id, err);
                 self.set(_.extend({}, defaults, {
                     connected: false,
                     currentHashrate: 0,
@@ -49,6 +50,7 @@ module.exports = Module.extend({
                         return callback(err);
                     }
 
+                    self.app.logger.debug('%s - fetched summary', self.id, JSON.stringify(data));
                     callback(null, self.handleSummaryResponse(data));
                 });
             },
@@ -58,6 +60,7 @@ module.exports = Module.extend({
                         return callback(err);
                     }
 
+                    self.app.logger.debug('%s - fetched devs', self.id, JSON.stringify(data));
                     callback(null, self.handleDevsResponse(data));
                 });
             },
@@ -67,11 +70,12 @@ module.exports = Module.extend({
                         return callback(err);
                     }
 
+                    self.app.logger.debug('%s - fetched pools', self.id, JSON.stringify(data));
                     callback(null, self.handlePoolsResponse(data));
                 });
             }
         ], function (err, results) {
-            var data = results[0],
+            var data = _.clone(results[0]),
                 devices = results[1],
                 pools = results[2];
 

lib/modules/notification/mail.js

@@ -35,6 +35,7 @@ module.exports = Module.extend({
                 var notifications = self.getNotifications(module.id, data);
 
                 notifications.forEach(function (notification) {
+                    self.app.logger.info('%s - sending notification', self.id, notification);
                     self.transport.sendMail({
                         from: self.config.from,
                         to: self.config.to,

lib/modules/revenue/triplemining.js

@@ -62,9 +62,16 @@ module.exports = Module.extend({
             var allRequestsSucceeded;
 
             if (err) {
+                self.app.logger.info('%s - error fetching revenue estimate from triplemining', self.id, err);
                 return;
             }
 
+            self.app.logger.debug(
+                '%s - fetched revenue estimate from triplemining',
+                self.id,
+                JSON.stringify(_.pluck(responses, 'statusCode')),
+                JSON.stringify(_.pluck(responses, 'body'))
+            );
             allRequestsSucceeded = _.all(responses, function (res) {
                 return res.statusCode === 200;
             });

lib/modules/technical/blockchainInfo.js

@@ -46,9 +46,16 @@ module.exports = Module.extend({
                 difficulty;
 
             if (err) {
+                self.app.logger.info('%s - error fetching data from blockchain.info', self.id, err);
                 return;
             }
 
+            self.app.logger.debug(
+                '%s - fetched data from blockchain.info',
+                self.id,
+                JSON.stringify(_.pluck(responses, 'statusCode')),
+                JSON.stringify(_.pluck(responses, 'body'))
+            );
             allRequestsSucceeded = _.all(responses, function (res) {
                 return res.statusCode === 200;
             });
@@ -57,7 +64,7 @@ module.exports = Module.extend({
             }
 
             difficulty = responses[0].body.difficulty;
-            self.set(_.extend(responses[0].body, {
+            self.set(_.extend({}, responses[0].body, {
                 btcPerBlock: responses[1].body / 1e8,
                 probability: 1 / (4295032833 * difficulty),
                 'hash_rate': responses[0].body['hash_rate'] * 1e3

package.json

@@ -49,7 +49,8 @@
         "serve-favicon": "2.0.0",
         "socket.io": "0.9.16",
         "stylus": "0.44.0",
-        "timespan": "2.3.0"
+        "timespan": "2.3.0",
+        "winston": "0.7.3"
     },
     "devDependencies": {
         "grunt-contrib-jshint": "0.10.0",

test/specs/lib/LoggerSpec.js

@@ -0,0 +1,33 @@
+'use strict';
+
+var chai = require('chai'),
+    expect = chai.expect,
+
+    winston = require('winston'),
+    Logger = require('../../../lib/Logger');
+
+describe('Logger', function () {
+    it('should use a default transport to console with log level info', function () {
+        var logger = new Logger();
+        expect(logger.transports.console).to.be.ok;
+        expect(logger.transports.console).to.be.an.instanceOf(winston.transports.Console);
+        expect(logger.transports.console.level).to.equal('info');
+    });
+
+    it('should use a default transport to console with the specified log level', function () {
+        var logger = new Logger({ level: 'debug' });
+        expect(logger.transports.console).to.be.ok;
+        expect(logger.transports.console).to.be.an.instanceOf(winston.transports.Console);
+        expect(logger.transports.console.level).to.equal('debug');
+    });
+
+    it('should use custom transports if specified', function () {
+        var transport = { name: 'custom', log: function () {}, on: function () {} },
+            logger = new Logger({
+                transports: [
+                    transport
+                ]
+            });
+        expect(logger.transports.custom).to.be.ok;
+    });
+});

test/specs/lib/modules/market/bitcoinchartsSpec.js

@@ -1,6 +1,8 @@
 'use strict';
 
 var chai = require('chai'),
+    sinon = require('sinon'),
+    sinonChai = require('sinon-chai'),
     expect = chai.expect,
     _ = require('lodash'),
     SandboxedModule = require('sandboxed-module'),
@@ -36,16 +38,30 @@ var chai = require('chai'),
         }
     });
 
+chai.use(sinonChai);
+
 describe('modules/market/bitcoincharts', function () {
+    var app;
+
+    beforeEach(function () {
+        app = { logger: { debug: sinon.stub(), info: sinon.stub() } };
+    });
 
     it('should get data from bitcoincharts correctly', function (done) {
-        var app = {},
-            config = {
+        var config = {
                 symbol: 'wantedSymbol'
             },
             bitcoincharts = new Bitcoincharts(app, config);
 
         bitcoincharts.on('change', function () {
+            expect(app.logger.debug).to.have.been.calledOnce;
+            expect(app.logger.debug).to.have.been.calledWith(
+                '%s - fetched markets from bitcoincharts.com',
+                bitcoincharts.id,
+                '200',
+                JSON.stringify(bitcoinChartsAnswer)
+            );
+
             expect(_.omit(bitcoincharts.toJSON(), 'historicalData')).to.deep.equal({
                 symbol: 'wantedSymbol',
                 ask: 14,
@@ -57,18 +73,26 @@ describe('modules/market/bitcoincharts', function () {
     });
 
     it('it should handle errors that occur during the request', function (done) {
-        var Bitcoincharts = SandboxedModule.require('../../../../../lib/modules/markets/bitcoincharts', {
+        var err = new Error('Test Error'),
+            Bitcoincharts = SandboxedModule.require('../../../../../lib/modules/markets/bitcoincharts', {
                 requires: {
                     'request': function (options, callback) {
                         setTimeout(function () {
-                            callback(new Error('Test Error'));
+                            callback(err);
                         }, 20);
                     }
                 }
             }),
-            bitcoincharts = new Bitcoincharts({}, {});
+            bitcoincharts = new Bitcoincharts(app, {});
 
         setTimeout(function () {
+            expect(app.logger.info).to.have.been.calledOnce;
+            expect(app.logger.info).to.have.been.calledWith(
+                '%s - error fetching markets from bitcoincharts.com',
+                bitcoincharts.id,
+                err
+            );
+
             expect(bitcoincharts.toJSON()).to.be.empty;
             done();
         }, 50);
@@ -84,7 +108,7 @@ describe('modules/market/bitcoincharts', function () {
                     }
                 }
             }),
-            bitcoincharts = new Bitcoincharts({}, {});
+            bitcoincharts = new Bitcoincharts(app, {});
 
         setTimeout(function () {
             expect(bitcoincharts.toJSON()).to.be.empty;
@@ -93,8 +117,7 @@ describe('modules/market/bitcoincharts', function () {
     });
 
     it('should set the title correctly', function () {
-        var app = {},
-            config = {
+        var config = {
                 symbol: 'wantedSymbol'
             },
             bitcoincharts = new Bitcoincharts(app, config);
@@ -104,7 +127,7 @@ describe('modules/market/bitcoincharts', function () {
 
     describe('set', function () {
         it('should add the bid, ask and close values to historicalData', function () {
-            var bitcoinCharts = new Bitcoincharts({}, {}),
+            var bitcoinCharts = new Bitcoincharts(app, {}),
                 now = new Date().getTime();
 
             bitcoinCharts.set({ ask: 1, bid: 2, close: 3 });