Shouldn't throw exception when it fails to log to logstash?

[soichih]

My application crashes if winston-logstash fails to connect to the logstash.

events.js:72
        throw er; // Unhandled 'error' event
              ^
Error: Max retries reached, transport in silent mode, OFFLINE
    at Socket.<anonymous> (/home/hayashis/git/isdp/node_modules/winston-logstash/lib/winston-logstash.js:197:26)
    at Socket.emit (events.js:95:17)
    at TCP.close (net.js:466:12)
16 Aug 20:18:50 - [nodemon] app crashed - waiting for file changes before starting...

In my own opinion, a logging library shouldn't cause the application to crash (don't throw exception) if it fails to log... but I am not sure if the author of this library agrees with that or not?

[jaakkos]

Could you provide more details like which winston version you are using?
I noticed that there is some changes in winston from 1.0.1 forward, which changes how it's handling error events or lack of it. I'll keep you updated when I find correct way to handle it.

[soichih]

I was using the latest version of winston / winston-logstash as of Aug 16.. I've removed winston-logstash already so I can't remember exactly which version it was.. Sorry!

[icecubed]

I seem to be having the same issue. I'm using the winston-logstash@0.2.11
Is there a way to safely handle the exception being thrown?

[williamoverton]

+1

[Alino]

+1

[joshje]

If you want to handle logstash errors, you can do so like this:

var logstash = new winston.transports.Logstash({ ... });
logstash.on('error', function(err) {
    console.error(err); // replace with your own functionality here
});

[soichih]

@joshje

Thanks for the info.

The reason why I reported this issue is not that I couldn't handle the error, but that winston-logstash should not cause application to crash under any circumstance; unhanded logging error / log file missing / log file full / can't write to log, etc, etc..

[Alino]

thank you @joshje , I fixed it with that in my project

[sandroacoelho]

@Alino , @soichih: Beside the @joshje solution, you can use max_connect_retries = -1, according winston-logstash docs:

max_connect_retries:

Max number of attempts to reconnect to logstash before going into silence.
-1 means retry forever.
Default: 4

Best,

[nitzan-blink]

I agree, the transport should not crash the application in any scenario.

@jaakkos using the proposed workaround suggested by @joshje no longer works.
the event hooking function .on('error') is called, but an error is still thrown afterwards, and the app crashes.
I am forced to override the logstashTransport.manager.onConnectionError function so the app won't crash.

is there a solution? (except hammering the server with retries indefinitely)

[jaakkos]

Hmmm, I think it depends on what kind of application it is and in what kind of environment. For example, if you are running an application handling money transactions, I would prefer it wouldn't run if the logging weren't working, and I feel it's better to close the system than keep it running. Another hand, if it's some hobby project which does something not essential and it's known that logging might sometimes fail, and it's accepted, then it's just fine.

I think I'll approach the issues with the following steps:

1. I have to write a test case for the .on('error') case to verify whether it's working or not correctly
2. I'll also check if https://github.com/winstonjs/winston#creating-your-own-logger exitOnError is working correctly

Any thoughts?

[nitzan-blink]

you have a valid point, but still, the developer should have the ability to at least choose if to allow crashing of the app, or not.
winston's exitOnError: false was the first thing I tried. I'm not sure how/where the exception is caught, maybe the transport should implement something to support it?
the steps you outlined sounds great, but if using exitOnError:false is not possible (to avoid the crash), then maybe this transport should have a similar option of its own?

[jaakkos]

@nitzan-blink btw which Winston version do you use? I am not sure if exitOnError is supported with the 2.x generation but I'll check.

[nitzan-blink]

I'm using Winston 3.8.2.

[jaakkos]

It seems that when using Winston 3.x the ```on('error')´´´ works but with the 2.X the stream pipping seems to be broken. Not sure why and when might be related to changes to Winston 2.X.

@nitzan-blink if you check the PRs test-bench/winston-3x/test/on_error_test.js

[nitzan-blink]

@jaakkos sorry but I'll have to limit our discussion to winston 3.x since I only use it.
in your test, didn't you get a subsequent crash after your .on('error') triggered?

my test env looks like:

const logstashTransport = new LogstashTransport({
port: LOGSTASH_PORT,
node_name: "logstash",
host: "127.0.0.1",
// max_connect_retries: -1,
// timeout_connect_retries: 500,
});
logstashTransport.on("error", function (err) {
console.error('.on("error") test');
});

and

const logger = createLogger({
  level: "info",
  format: format.json(),
  defaultMeta: { service: process.env.SERVICE_NAME, env: process.env.ENV_TYPE },
  transports: [
    new transports.Console({
      format: format.combine(format.colorize(), alignColorsAndTime),
    }),
    logstashTransport,
  ],
  exitOnError: false,
});

when running with no logstash instance on "127.0.0.1", the app crashes, and I get this on console:

.on("error") test
Waiting for the debugger to disconnect...
node:events:491
      throw er; // Unhandled 'error' event
      ^

Error: Max retries reached, transport in silent mode, OFFLINE
    at Manager.onConnectionError (/Users/nitzan/test/node_modules/.pnpm/winston-logstash@1.1.0_winston@3.8.2/node_modules/winston-logstash/lib/manager.js:84:26)
    at Object.onceWrapper (node:events:628:26)
    at Manager.emit (node:events:513:28)
    at PlainConnection.socketOnError (/Users/nitzan/test/node_modules/.pnpm/winston-logstash@1.1.0_winston@3.8.2/node_modules/winston-logstash/lib/connection.js:24:18)
    at Object.onceWrapper (node:events:628:26)
    at Socket.emit (node:events:513:28)
    at emitErrorNT (node:internal/streams/destroy:157:8)
    at emitErrorCloseNT (node:internal/streams/destroy:122:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
Emitted 'error' event on DerivedLogger instance at:
    at DerivedLogger.transportEvent (/Users/nitzan/test/node_modules/.pnpm/winston@3.8.2/node_modules/winston/lib/winston/logger.js:639:12)
    at LogstashTransport.emit (node:events:525:35)
    at LogstashTransport.onError (/Users/nitzan/test/node_modules/.pnpm/winston-logstash@1.1.0_winston@3.8.2/node_modules/winston-logstash/lib/winston-logstash-latest.js:23:10)
    at Manager.emit (node:events:513:28)
    at Manager.onConnectionError (/Users/nitzan/test/node_modules/.pnpm/winston-logstash@1.1.0_winston@3.8.2/node_modules/winston-logstash/lib/manager.js:84:12)
    at Object.onceWrapper (node:events:628:26)
    [... lines matching original stack trace ...]
    at Socket.emit (node:events:513:28)

[jaakkos]

You should add the on('error', ... handler for the logger in the case of Winston 3.x.
Similar as I wrote in the test https://github.com/jaakkos/winston-logstash/blob/5c46c627edd9daf0fbbb33bf849b1db81ca24f09/test-bench/winston-3x/test/on_error_test.js

const logger = createLogger({ . . . your configuration and passing the LogstashTransport . . .})

logger.on('error', (error) => {
 // handle errors in the logger here
 console.log('Error from logger:', error)
});

logger.info('foo', 'bar'):

Then it should not throw the exception because there are listeners for the error event.
Could you test that?

[nitzan-blink]

@jaakkos when used like that, the app doesn't crash.
but a few questions arise:

1. why is the previously mentioned workaround of listening to the transport's error changed, and is not able to stop the crash?
2. I'm already using winston's exitOnError: false, why do I have to listen and handle the errors of winston?

[jaakkos]

@jaakkos when used like that, the app doesn't crash. but a few questions arise:

1. why is the previously mentioned workaround of listening to the transport's error changed, and is not able to stop the crash?

That workaround was for Winston >=2.x and with the Winston 3.x the same logic doesn't work because the Winston implementation is different. Did you migrate from 2.x to 3.x or what was your path in this case? There are quite many changes when migrating to 3.x, have you checked the https://github.com/winstonjs/winston/blob/222c86341df7cb8065d6fa0f78de50a445db2e4b/UPGRADE-3.0.md#exceptions--exception-handling

2. I'm already using winston's exitOnError: false, why do I have to listen and handle the errors of winston?

My thoughts;

It says on the documentation

exitOnError true If false, handled exceptions will not cause process.exit
https://github.com/winstonjs/winston#creating-your-own-logger

I am not sure what handled exceptions means in this context. How I would understand it is; if some exception is thrown in the application code, but there is a catch block somewhere to catch the exception, the logger will write the exception to log and try to continue. How this will work will be application-specific logic combined with Winston. There isn't any error case if logging itself is not working.

For errors happening inside the Winston itself and this case, in the transport, you should listen to the error from the logger with logger.on('error', ...) and, on that code, decide if the error is okay or should we halt the whole process which is not related to the application itself.

Did you catch my idea of the separation of duties?

disclaimer 😉
I am not an expert on Winston, and I think you should open I discussion about best practices for error handling at https://github.com/winstonjs/winston

[nitzan-blink]

That workaround was for Winston >=2.x and with the Winston 3.x the same logic doesn't work because the Winston implementation is different. Did you migrate from 2.x to 3.x or what was your path in this case? There are quite many changes when migrating to 3.x, have you checked the https://github.com/winstonjs/winston/blob/222c86341df7cb8065d6fa0f78de50a445db2e4b/UPGRADE-3.0.md#exceptions--exception-handling

I didn't migrate from v2, I just started using in v3.

My thoughts;

It says on the documentation

exitOnError true If false, handled exceptions will not cause process.exit
https://github.com/winstonjs/winston#creating-your-own-logger

I am not sure what handled exceptions means in this context. How I would understand it is; if some exception is thrown in the application code, but there is a catch block somewhere to catch the exception, the logger will write the exception to log and try to continue. How this will work will be application-specific logic combined with Winston. There isn't any error case if logging itself is not working.

tried looking closer into what you wrote, and it seems that this

exitOnError true If false, handled exceptions will not cause process.exit

is a typo:
winstonjs/winston#1898
and according to https://github.com/winstonjs/winston#to-exit-or-not-to-exit:

By default, winston will exit after logging an uncaughtException. If this is not the behavior you want, set exitOnError = false

so that flag apparently is not related to inner winston exceptions, but to broader exception handling with/without winston, and in any case irrelevant for the issue I'm facing (please correct me if I'm wrong, and you understood differently).

For errors happening inside the Winston itself and this case, in the transport, you should listen to the error from the logger with logger.on('error', ...) and, on that code, decide if the error is okay or should we halt the whole process which is not related to the application itself.

seems like this is the only solution we currently have..
but the question is, is there something the transport (winston-logstash) can (or should?) do to prevent this, since it's a connection based transport?

[jaakkos]

If you check the implementation of that feature in the Winston, it's attaching a process exit hook which prevents the exit; I feel that I wouldn't use that approach in any production code because it could leave the application in an unpredicted state which is in my experience always a bad situation to be.

You always have multiple a solution, as this is open source project 😄

• You can fork the project, make any changes you want, and use that solution.
• You could create PR which addresses this issue in a backwards-compatible manner with tests and documentation, and we can continue this discussion. If you feel your solution would help others as this project has helped you.
• Write your transport which perfectly meets your requirements

While this is a relatively complex transport with an internal state and IO, I think the current solution is the yet best approach to network failure. Transport is transparent about the errors and lets the user decide what to do in the case of an error. Suppose the developer chooses not to address them, it fallback to a safe default, an exception that stops the process. I think this way; it's simple but not always easy. This is my rationale for the functionality.

[jaakkos]

I'll close the issue and write that rationale in the README.