Fix Issue where winston removes transport on error (#1364)

[yinzara]

#1364

[yinzara]

This is a pretty big bug. Any chance we could get some love from the maintainers?

[felix-hoc]

Could we get this merged?

[yinzara]

Can someone with write access please merge this? :)

[cjbarth]

It appears that the CI build failed because of a problem with the CI builder (it couldn't find node@10). So, we need someone to kick another build, or @yinzara could push a little change to kick it again (or squash commits on this PR branch and force-push). Or there are a few linting errors that could be addressed, particularlly easy to fix should be the no-shadow ones:

C:\projects\winston\lib\winston\logger.js
   81:12  warning  Method 'configure' has a complexity of 17                               complexity
   81:12  warning  Method 'configure' has too many statements (20). Maximum allowed is 15  max-statements
  201:6   warning  Method 'log' has a complexity of 12                                     complexity
  201:6   warning  Method 'log' has too many statements (24). Maximum allowed is 15        max-statements
C:\projects\winston\lib\winston\tail-file.js
  63:57  warning  Arrow function has a complexity of 13                               complexity
  63:57  warning  Arrow function has too many statements (30). Maximum allowed is 15  max-statements
  63:58  warning  'err' is already declared in the upper scope                        no-shadow
C:\projects\winston\lib\winston\transports\console.js
  44:6  warning  Method 'log' has too many statements (19). Maximum allowed is 15  max-statements
C:\projects\winston\lib\winston\transports\file.js
  263:18  warning  'buff' is already declared in the upper scope     no-shadow
  324:29  warning  'options' is already declared in the upper scope  no-shadow
✖ 10 problems (0 errors, 10 warnings)

[cjbarth]

@yinzara Thank you for your responsiveness on this, however, it seems that now a valid test is failing. It doesn't seem like your code recent change caused it. I wish I knew why this were failing now. Do these tests pass locally for you?

  1) Logger, ExceptionHandler
       Custom exitOnError function does not exit:
     Uncaught Unknown assertation failure occured, assumed `[]` to deeply equal `[ 'Ignore this error' ]`
  C:\projects\winston\test\log-exception.test.js
                                    v
      66.       assume(child.killed).false();
      67.       assume(stdout).deep.equals(['Ignore this error']);
      68.       child.kill();
                                    ^
          at Assume.equal (node_modules\assume\index.js:676:15)
          at Timeout._onTimeout (test\log-exception.test.js:67:27)

[yinzara]

I rebased on master. Let's see if that fixes it.

[cjbarth]

@yinzara That seemed to fix it, however, now we are back to the problem with node not being found. Is there a maintainer that can help with this? @DABH would you know why we are getting this AppVeyor problems?

Error: Cannot find module 'C:\projects\winston\node'
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:636:15)
    at Function.Module._load (internal/modules/cjs/loader.js:562:25)
    at Function.Module.runMain (internal/modules/cjs/loader.js:831:12)
    at startup (internal/bootstrap/node.js:283:19)
    at bootstrapNodeJSCore (internal/bootstrap/node.js:623:3)
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! [email protected] test:mocha: `mocha test/*.test.js test/**/*.test.js --exit`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the [email protected] test:mocha script.

[DABH]

Hi folks,

Thank you all for your work on this. Three comments--

1. I think it's pretty safe to ignore the Appveyor failures. It would be good to get to the bottom of these, but they're common to many of the open PRs, so it's not the fault of this PR.

2. I agree this design solves the issue - the transport gets re-added after an error is thrown - but would it be better to just not remove the transport in the first place (rather than deleting and re-adding), if that is the ultimate goal?

3. Finally, I wonder whether this is really the desired behavior. If a transport throws an error, I think the meaning of that is supposed to be like the transport is no longer valid / can no longer be logged to. So why bother having it in the logger anymore. (E.g. if a transport is failed, continuing to log to it will just generate a slew of error messages in your logs.) If you have a case where you want to ignore this and keep logging even if your transport goes into an error state, should it be "your" (your application's) job to re-add the transport (or, a presumably fresh and working copy of the transport)? Or should this behavior be optional at least, where this "zombie mode" for the transport is off by default but can be turned on if you need it?

Again, really appreciate all the thought and work put into this -- thank you and let me know your thoughts!

[yinzara]

1. Thanks!
2. While I wish that was an option in "readable-stream" to disable this functionality but without completely swapping this library, all transport errors will cause the stream to unpipe itself. We could possibly use some kind of transform stream to ignore errors on write but that would mean the errors would be completely ignored all together instead of propagating out of the logger in an error event.
3. I think the assumption that a single error from a transport implies the transport is permanently dead is a pretty crazy one especially since many of the transports are ones that go over a network. I do think the assumption that adding a transport to a logger should imply that transport is part of that logger until removed, no matter if it produced an error or not. In the vast majority of the cases, a single transport error does not mean the transport is completely invalid. I think that's really an edge case. If you do want the existing functionality of removing the transport if it fails, I think requiring that the app developer specifically handle the error and remove the transport is a much more reasonable request (since it's the minority case and something intentional).

[cjbarth]

@DABH Is there anything that prevents this from landing that we can perhaps help to address?

[DABH]

Thanks for the replies, I think this makes sense to have this as the default behavior. Will go ahead and merge. Thanks again for your contribution!