Error formats incorrectly

[eurostar-fennec-cooper]

The error formatter example describes that it will log:

// Error: Oh no!
//     at repl:1:13
//     at ContextifyScript.Script.runInThisContext (vm.js:50:33)
//     at REPLServer.defaultEval (repl.js:240:29)
//     at bound (domain.js:301:14)
//     at REPLServer.runBound [as eval] (domain.js:314:12)
//     at REPLServer.onLine (repl.js:468:10)
//     at emitOne (events.js:121:20)
//     at REPLServer.emit (events.js:211:7)
//     at REPLServer.Interface._onLine (readline.js:282:10)
//     at REPLServer.Interface._line (readline.js:631:8)

Whereas it really logs:
{ level: undefined, message: 'Oh no!', stack: 'Error: Oh no!\n at Object.<anonymous> (C:\\Users\\Fennec\\Documents\\errlog.js:6:37)\n at Module._compile (internal/modules/cjs/loader.js:688:30)\n at Object.Module._extensions..js (internal/modules/cjs/loader.js:699:10)\n at Module.load (internal/modules/cjs/loader.js:598:32)\n at tryModuleLoad (internal/modules/cjs/loader.js:537:12)\n at Function.Module._load (internal/modules/cjs/loader.js:529:3)\n at Function.Module.runMain (internal/modules/cjs/loader.js:741:12)\n at startup (internal/bootstrap/node.js:285:19)\n at bootstrapNodeJSCore (internal/bootstrap/node.js:739:3)', [Symbol(level)]: undefined, [Symbol(message)]: 'Oh no!' }

[AddoSolutions]

Same issue here.

Using t he exact code from the docs:

const { format } = require('logform');
const { errors } = format;
 
const errorsFormat = errors({ stack: true })
 
const info = errorsFormat.transform(new Error('Oh no!'));
 
console.log(info);

you get:

module.exports = format((einfo, { stack }) => {
                                  ^

TypeError: Cannot destructure property 'stack' of 'undefined' as it is undefined.
    at Format.transform (/Users/user/Sites/project/node_modules/logform/errors.js:14:35)
    at Object.<anonymous> (/Users/user/Sites/project/src/logger.js:104:27)
    at Module._compile (internal/modules/cjs/loader.js:1201:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1221:10)
    at Module.load (internal/modules/cjs/loader.js:1050:32)
    at Function.Module._load (internal/modules/cjs/loader.js:938:14)
    at Module.require (internal/modules/cjs/loader.js:1090:19)
    at require (internal/modules/cjs/helpers.js:75:18)
    at Object.<anonymous> (/Users/user/Sites/project/index.js:4:16)
    at Module._compile (internal/modules/cjs/loader.js:1201:30)

[xeroxoid]

Yeah same here. It seems that the stack is JSON.strigified and thus escapes newline characters. In winston I tried using a custom format instead (with format.printf) but it becomes a mess when you want to include errors and metadata.

The other issue is that logging without a message as the first argument supresses both the error's message and the stack. So you(in winston) with logger.error('message', new Error('with message')) it works but logger.error(new Error('without message')) does not.

[xenoterracide]

yeah, same complaint, doing this with splat is nicer :/

      log.error('%O', new Error('my error'));

[opitzmic]

Ran into the same issue just now.

With winston 3.3.3, the following does not work as expected:

const winston = require('winston')

const logger = winston.createLogger({
  transports: [
    new winston.transports.Console({
      format: winston.format.errors(),
    })
  ]
})

logger.error(new Error('I am Error')) // Prints `{"level":"error"}`

Looks like the error properties get dropped when doing Object.assign({}, info) in winston-transport/index.js, line 91

There's a workaround: Apply the errors format before passing the log message to the transports:

const winston = require('winston')

const logger = winston.createLogger({
  format: winston.format.errors(),
  transports: [
    new winston.transports.Console()
  ]
})

logger.error(new Error('I am Error')) // Prints `I am Error`

[aduponchel]

Same when running the example :

const {format} = require('logform');
const {errors} = format;

const errorsFormat = errors({stack: true});

const info = errorsFormat.transform(new Error('Oh no!'));

console.log(info);
// Error: Oh no!
//     at repl:1:13
//     at ContextifyScript.Script.runInThisContext (vm.js:50:33)
//     at REPLServer.defaultEval (repl.js:240:29)
//     at bound (domain.js:301:14)
//     at REPLServer.runBound [as eval] (domain.js:314:12)
//     at REPLServer.onLine (repl.js:468:10)
//     at emitOne (events.js:121:20)
//     at REPLServer.emit (events.js:211:7)
//     at REPLServer.Interface._onLine (readline.js:282:10)
//     at REPLServer.Interface._line (readline.js:631:8)

Error:

module.exports = format((einfo, { stack }) => {
                                  ^

TypeError: Cannot destructure property 'stack' of 'undefined' as it is undefined.
    at Format.transform (/home/aduponchel/royalcanin/node_modules/logform/errors.js:14:35)
    at Object.<anonymous> (/home/aduponchel/royalcanin/demo/winston.js:7:27)
    at Module._compile (internal/modules/cjs/loader.js:1072:14)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1101:10)
    at Module.load (internal/modules/cjs/loader.js:937:32)
    at Function.Module._load (internal/modules/cjs/loader.js:778:12)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:76:12)
    at internal/main/run_main_module.js:17:47

Node v14.17.4
NPM 6.14.14
Logform 2.2.0

[cyrilchapon]

This has to be addressed; as there is currently no solution at all to correctly handle logger.error(anyErrorInstance).

I digged into it; by first copy pasting the logform.format.errors code

const errFormat = Logform.format((einfo, { stack, cause }) => {
  console.log('IM HERE')
  console.log(einfo)
  if (einfo instanceof Error) {
    const info = Object.assign({}, einfo, {
      level: einfo.level,
      [LEVEL]: einfo[LEVEL] || einfo.level,
      message: einfo.message,
      [MESSAGE]: einfo[MESSAGE] || einfo.message,
    })

    if (stack) info.stack = einfo.stack
    if (cause) info.cause = einfo.cause
    return info
  }

  if (!(einfo.message instanceof Error)) return einfo

  // Assign all enumerable properties and the
  // message property from the error provided.
  const err = einfo.message
  Object.assign(einfo, err)
  einfo.message = err.message
  einfo[MESSAGE] = err.message

  // Assign the stack and/or cause if requested.
  if (stack) einfo.stack = err.stack
  if (cause) einfo.cause = err.cause
  return einfo
})

This is a total nonsense; as (thanks to @opitzmic )

the error properties get dropped when doing Object.assign({}, info) in winston-transport/index.js, line 91

As a consequence, einfo has no chance to be an Error instance by any means; and leads to a completely broken logic.

---

Since it's done at the transport level; there is basically nothing we can do inside formatters that could workaround this.

[paul-uz]

Any updates?

[DABH]

Open to PRs that the community feels solves things in the right way here (whether at the Winston, Winston-transport, or logform level). I don’t have much time to investigate this but if someone made a well-tested / backwards-compatible PR that articulated why it addressed these issues, it’d be easy for me to approve and do a release. (Or if there’s no backwards compatible way to do this - could fix via a major version bump to winston…)

[wbt]

An update to documentation/example code might also be an improvement.

[DABH]

I think I saw a comment on here briefly (since deleted) asking for updates... any contributions that folks feel improves the behavior here (even if that's just better docs/examples) are absolutely welcomed and will be reviewed. We appreciate the Winston userbase and value any community contributions.