Merge pull request #328 from ripple/fix-remote-error-log

Fix error logging on Remote for object-type messages

src/index.js

@@ -23,6 +23,7 @@ exports.RangeSet = require('./rangeset').RangeSet;
 exports.convertBase = require('./baseconverter');
 
 exports._test = {
+  Log: require('./log'),
   PathFind: require('./pathfind').PathFind,
   TransactionManager: require('./transactionmanager').TransactionManager
 };

src/log.js

@@ -1,5 +1,7 @@
 'use strict';
 
+const assert = require('assert');
+
 /**
  * Logging functionality for ripple-lib and any applications built on it.
  *
@@ -34,13 +36,13 @@ function Log(namespace) {
  * @return {Log} sub logger
  */
 Log.prototype.sub = function(namespace) {
-  var subNamespace = this._namespace.slice();
+  const subNamespace = this._namespace.slice();
 
   if (namespace && typeof namespace === 'string') {
     subNamespace.push(namespace);
   }
 
-  var subLogger = new Log(subNamespace);
+  const subLogger = new Log(subNamespace);
   subLogger._setParent(this);
   return subLogger;
 };
@@ -51,7 +53,7 @@ Log.prototype._setParent = function(parentLogger) {
 
 Log.makeLevel = function(level) {
   return function() {
-    var args = Array.prototype.slice.apply(arguments);
+    const args = Array.prototype.slice.apply(arguments);
     args[0] = this._prefix + args[0];
     Log.engine.logObject.apply(Log, [level].concat(args[0], [args.slice(2)]));
   };
@@ -69,7 +71,7 @@ Log.prototype.error = Log.makeLevel(4);
  */
 
 function getLogInfo(message, args) {
-  var stack = new Error().stack;
+  const stack = new Error().stack;
 
   return [
     // Timestamp
@@ -102,15 +104,17 @@ function logMessage(logLevel, args) {
   }
 }
 
+const engines = {};
+
 /**
  * Basic logging connector.
  *
  * This engine has no formatting and works with the most basic of 'console.log'
  * implementations. This is the logging engine used in Node.js.
  */
-var BasicLogEngine = {
-  logObject: function logObject(level, message, args) {
-    args = args.map(function(arg) {
+engines.basic = {
+  logObject: function logObject(level, message, args_) {
+    const args = args_.map(function(arg) {
       return JSON.stringify(arg, null, 2);
     });
 
@@ -125,9 +129,9 @@ var BasicLogEngine = {
  * JavaScript objects. This connector passes objects through to the logging
  * function without any stringification.
  */
-var InteractiveLogEngine = {
-  logObject: function(level, message, args) {
-    args = args.map(function(arg) {
+engines.interactive = {
+  logObject: function(level, message, args_) {
+    const args = args_.map(function(arg) {
       return /MSIE/.test(navigator.userAgent)
       ? JSON.stringify(arg, null, 2)
       : arg;
@@ -136,22 +140,33 @@ var InteractiveLogEngine = {
     logMessage(level, getLogInfo(message, args));
   }
 };
+
 /**
  * Null logging connector.
  *
  * This engine simply swallows all messages. Used when console.log is not
  * available.
  */
-var NullLogEngine = {
+engines.none = {
   logObject: function() {}
 };
 
+Log.getEngine = Log.prototype.getEngine = function() {
+  return Log.engine;
+};
+
+Log.setEngine = Log.prototype.setEngine = function(engine) {
+  assert.strictEqual(typeof engine, 'object');
+  assert.strictEqual(typeof engine.logObject, 'function');
+  Log.engine = engine;
+};
+
 if (typeof window !== 'undefined' && typeof console !== 'undefined') {
-  Log.engine = InteractiveLogEngine;
+  Log.setEngine(engines.interactive);
 } else if (typeof console !== 'undefined' && console.log) {
-  Log.engine = BasicLogEngine;
+  Log.setEngine(engines.basic);
 } else {
-  Log.engine = NullLogEngine;
+  Log.setEngine(engines.none);
 }
 
 /**
@@ -171,3 +186,8 @@ module.exports.internal = module.exports.sub();
  * Expose the class as well.
  */
 module.exports.Log = Log;
+
+/**
+ * Expose log engines
+ */
+module.exports.engines = engines;

src/server.js

@@ -5,6 +5,7 @@ const util = require('util');
 const url = require('url');
 const LRU = require('lru-cache');
 const EventEmitter = require('events').EventEmitter;
+const RippleError = require('./').RippleError;
 const Amount = require('./amount').Amount;
 const RangeSet = require('./rangeset').RangeSet;
 const log = require('./log').internal.sub('server');
@@ -19,20 +20,21 @@ const log = require('./log').internal.sub('server');
  *    @param [Boolean] securec
  */
 
-function Server(remote, _opts) {
+function Server(remote, opts_) {
   EventEmitter.call(this);
 
   const self = this;
   let opts;
-  if (typeof _opts === 'string') {
-    const parsedUrl = url.parse(_opts);
+
+  if (typeof opts_ === 'string') {
+    const parsedUrl = url.parse(opts_);
     opts = {
       host: parsedUrl.hostname,
       port: parsedUrl.port,
       secure: (parsedUrl.protocol === 'ws:') ? false : true
     };
   } else {
-    opts = _opts;
+    opts = opts_;
   }
 
   if (typeof opts !== 'object') {
@@ -44,10 +46,10 @@ function Server(remote, _opts) {
       'Server host is malformed, use "host" and "port" server configuration');
   }
 
-  // We want to allow integer strings as valid port numbers
-  // for backward compatibility
+  // We want to allow integer strings as valid port numbers for backward
+  // compatibility
   opts.port = Number(opts.port);
-  if (!opts.port) {
+  if (isNaN(opts.port)) {
     throw new TypeError('Server port must be a number');
   }
 
@@ -67,13 +69,11 @@ function Server(remote, _opts) {
   this._shouldConnect = false;
   this._state = 'offline';
   this._ledgerRanges = new RangeSet();
-  this._ledgerMap = new LRU({
-    max: 200
-  });
+  this._ledgerMap = new LRU({max: 200});
 
   this._id = 0; // request ID
   this._retry = 0;
-  this._requests = { };
+  this._requests = {};
 
   this._load_base = 256;
   this._load_factor = 256;
@@ -266,7 +266,7 @@ Server.prototype.requestServerID = function() {
     try {
       self._pubkey_node = message.info.pubkey_node;
     } catch (e) {
-      // empty
+      log.warn('Failed to get server pubkey_node', message);
     }
   });
 
@@ -293,8 +293,8 @@ Server.prototype._updateScore = function(type, data) {
   }
 
   const weight = this._scoreWeights[type] || 1;
-
   let delta;
+
   switch (type) {
     case 'ledgerclose':
       // Ledger lag
@@ -305,6 +305,7 @@ Server.prototype._updateScore = function(type, data) {
       break;
     case 'response':
       // Ping lag
+      // Servers are not pinged by default
       delta = Math.floor((Date.now() - data.time) / 200);
       this._score += weight * delta;
       break;
@@ -333,7 +334,7 @@ Server.prototype._remoteAddress = function() {
   try {
     return this._ws._socket.remoteAddress;
   } catch (e) {
-    // empty
+    log.warn('Cannot get remote address. Does not work in browser');
   }
 };
 
@@ -442,7 +443,20 @@ Server.prototype.connect = function() {
   self.emit('connecting');
 
   ws.onmessage = function onMessage(msg) {
-    self.emit('message', msg.data);
+    let message = msg.data;
+
+    try {
+      message = JSON.parse(message);
+    } catch (e) {
+      const error = new RippleError('unexpected',
+        'Unexpected response from server: ' + JSON.stringify(message));
+
+      self.emit('unexpected', message);
+      log.error(error);
+      return;
+    }
+
+    self.emit('message', message);
   };
 
   ws.onopen = function onOpen() {
@@ -559,15 +573,6 @@ Server.prototype._handleClose = function() {
  */
 
 Server.prototype._handleMessage = function(message) {
-  try {
-    // this is fixed in Brandon's pull request
-    /* eslint-disable no-param-reassign */
-    message = JSON.parse(message);
-    /* eslint-enable no-param-reassign */
-  } catch (e) {
-    // empty
-  }
-
   if (!Server.isValidMessage(message)) {
     this.emit('unexpected', message);
     return;

test/server-test.js

@@ -1,5 +1,7 @@
 'use strict';
+
 /* eslint-disable no-new */
+
 const _ = require('lodash');
 const assert = require('assert');
 const ws = require('ws');