[SER-281] Log Errors

[mountHouli]

Jira Ticket(s)

SER-281

To Test

Test 1

yarn test.

Test 2 (optional):

Step A: Setup logging

In format.test.js, in each of the beforeEach() callbacks that specify a jest mock function (e.g. spy = jest.fn()), add this logging statement: console.log(expectedMessage);

Step B: Setup script

In package.json, add this script "test-with-logging": "yarn install && jest --verbose=false",

Step C: Run it

yarn test-with-logging

Results: Logged to your terminal should be each of the desired outcomes listed in the jira ticket.

[orndorffgrant]

Very 🔥

[rmharrison]

TL;DR

The function signatures don't work quite how I expected. Some of this is bunyan vs winston signature standards.

Most are edge-cases that behave unexpectedly.

• Which are behaving as you expect?
• Which, if any, should be supported?

And thank you for explicitly enumerating all of the test cases!

In 20+ test cases, the only enumerated test case that doesn't behave as I expected is (B), the concatenation of LoggerMsg and ErrorMsg with logger.error("LoggerMsg", new Error("ErrorMsg"))

FFR: To reproduce, copy/paste the lines from the README.md:L13-32 and use the logger.error signatures enumerated below.

(A) Resolved: I was surprised that the err first signature didn't work (this is a difference with bunyan)

logger.error(new Error('abc'), 'msg')
{
  "service": "test-service",
  "logger": "Winston-JSON-Formatter",
  "hostname": "...",
  "level": "error",
  "msg": {},
  "meta": {
    "service": {
      "version": "1.0.0",
      "node_env": ""
    },
    "logger": {
      "time": "2019-04-09T23:00:31.789Z"
    },
    "event": {}
  }
}

• No err, but this is expected from the winston standard.

Thank you for linking the specific winston fix PR in your JIRA issue: winstonjs/winston#1562 (comment)
Here, they enumerate the supported signatures, which does not include err first.

(B) Unresolved: LoggerMsg and ErrorMsg behaviour

Unexpected...

> logger.error('LoggerMsg', new Error('ErrorMsg'))
{
  "service": "test-service",
  "logger": "Winston-JSON-Formatter",
  "hostname": "...",
  "level": "error",
  "msg": "LoggerMsgErrorMsg", # <~~~ Concatated LoggerMsg and ErrorMsg
  "meta": {
    "service": {
      "version": "1.0.0",
      "node_env": ""
    },
    "logger": {
      "time": "2019-04-09T23:04:01.682Z"
    },
    "event": {}
  },
  "err": {
    "stack": "..." # <~~~ err.name doesn't appear
  }
}

• LoggerMsg and ErrorMsg are concatinated
• err.name doesn't appear

Expected...

> logger.error(new Error('ErrorMsg'))
{
  "service": "test-service",
  "logger": "Winston-JSON-Formatter",
  "hostname": "...",
  "level": "error",
  "msg": "ErrorMsg",
  "meta": {
    "service": {
      "version": "1.0.0",
      "node_env": ""
    },
    "logger": {
      "time": "2019-04-09T23:05:30.698Z"
    },
    "event": {}
  },
  "err": {
    "name": "Error",
    "stack": "..."
  }
}

err.name appears as expected.

(C) Unresolved: Unsupported signature: Err, {}

> logger.error(new Error('ErrorMsg'), {a: 'a', b: 'b'})
{
  "service": "test-service",
  "logger": "Winston-JSON-Formatter",
  "hostname": "...",
  "level": "error",
  "msg": {},
  "meta": {
    "service": {
      "version": "1.0.0",
      "node_env": ""
    },
    "logger": {
      "time": "2019-04-09T23:11:57.836Z"
    },
    "event": {
      "a": "a",
      "b": "b"
    }
  }
}

• No err

(D) Unresolved: Unsupported signature: FunctionMsg, Err, {}

> logger.error('LoggerMsg', new Error('ErrorMsg'), {a: 'a', b: 'b'})
{
  "service": "test-service",
  "logger": "Winston-JSON-Formatter",
  "hostname": "Hargrove",
  "level": "error",
  "msg": "LoggerMsgErrorMsg",
  "meta": {
    "service": {
      "version": "1.0.0",
      "node_env": ""
    },
    "logger": {
      "time": "2019-04-09T23:12:57.049Z"
    },
    "event": {} # <~~~ {a: 'a', b: 'b'} don't appear here
  },
  "err": {
    "stack": "..."
  }
}

Clarification

Currently, code is not "magic" and appears under meta.event
If code is part of an Error object, should it appear under err.code?

[rmharrison]

Please update readme:

• Update JSON log format
• New screenshot for console logger

[mountHouli]

Regarding item (B)

The concatenated messages are a winston bug. See winstonjs/winston#1634

The lack of err.name / info.name is a winston bug. See winstonjs/winston#1635

Regarding item (C)

Fixed. See commit a8ed890

Regarding item (D)

This case is not supported by winston. See examples in winstonjs/winston#1562