Error logging

[Stefan-Hanke]

This PR starts at server-side error logging - #253. It allows to parameterize the server with a log fn that is subsequently called on events and moves that got rejected.

Actually, I don't know what returning an object fron a message handler does? Is this printed to console.log?

Checklist

• Use a separate branch in your local repo (not master).
• Test coverage is 100% (or you have a story for why it's ok).

[coveralls]

Coverage remained the same at 100.0% when pulling bcb63ef on Stefan-Hanke:error_logging into 510977f on google:master.

[nicolodavis]

Can you sync this with 1688639? That commit moves this code to src/master/master.js.

[nicolodavis]

I'm guessing the name clash with log here is problematic?

[nicolodavis]

Instead of parameterizing Server (which will get messy now that you have to pass this down many layers after #251), how about we just expose a logging module that is imported here and used? I don't actually imagine that people will want anything other than console.log, so instead of allowing a custom logger implementation, let's just turn it off in production builds?

Also, I think different logging levels make sense, which is easy to do if we just add two functions in the logging module:

// turned off in prod builds
// used for general diagnostic messages
logging.info()

// always on
// signals an unexpected value or other error
logging.error()

[nicolodavis]

What is the reason that spying doesn't work? You can also try:

jest.spyOn(console, log)

[Stefan-Hanke]

Once the import is evaluated it is fixed on either production or not, but I want to test both.

[nicolodavis]

I think checking against these variables at each log call will eventually slow things down once we have a lot of logging.
Can you try the spy suggestion above and change this to something along the lines of:

let info = () => {};
let error = () => {};

if (DEV) {
  info = (msg) => console.log(...);
  error = (msg) => console.log(...);
}

[Stefan-Hanke]

OK maybe that comment is misleading. What is meant is that once the module is imported, NODE_ENV is evaluted and the calls are either routed to console.log or not. Once fixed to console.log, it cannot be altered by a test anymore (in the sense that it is NOT called whatsoever) since that would require "running" the module again, evaluating NODE_ENV again after the test changed it.

My intention is to have tests that actually check that console.log is called when NODE_ENV==="test"|"development", and NOT called otherwise.

[nicolodavis]

I think you can accomplish this by some combination of jest.resetModules() and a require() statement to import the module (don't use the ES5 module import syntax).

[nicolodavis]

beforeEach(() => {
  jest.resetModules();   // this may or may not be actually necessary.
});

describe('dev', () => {
  process.env.NODE_ENV = 'development';
  const logger = require('./logger');
  ...
});

describe('prod', () => {
  process.env.NODE_ENV = 'production';
  const logger = require('./logger');
  ...
});

[nicolodavis]

Using two separate test files is also an option if this doesn't work.

[nicolodavis]

I inlined master.log.test.js in master.test.js. Having an extra test file that does the same setup work as master.test.js is not worth the additional slowdown of running the entire test suite on the CI.