Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[patch] A method to wait until all the logs are physically sent to winston #128

Closed
pv4 opened this issue Jan 13, 2023 · 3 comments · Fixed by #130
Closed

[patch] A method to wait until all the logs are physically sent to winston #128

pv4 opened this issue Jan 13, 2023 · 3 comments · Fixed by #130

Comments

@pv4
Copy link

pv4 commented Jan 13, 2023

Hello!

I use winston-loki in many projects and in case of unfixable runtime errors I log the error and throw an uncaughtable exception to end nodejs execution. Something like the following (I replaced the throw by process.exit(0) to simplify the output if you run the demo yourself):

const
  winston = require('winston'),
  winstonLoki = require('winston-loki');

const loggerTransport = new winstonLoki({
  host: "http://127.0.0.1:22222",
  batching: false });

const logger = winston.createLogger({
  transports:[ loggerTransport ] });

(async ()=>{
  logger.log('info', "Error happened");
  process.exit(0);
})();

But in this case the error doesn't get to grafana even with batching: false. It appears to be related to asynchronous nature of nodejs. Briefly, logger.log() doesn't mean "send the log to grafana" but instead it means "start sending the log to grafana and return execution to the caller without waiting the response from grafana". In the case above right after the start process.exit(0) is called and nodejs exits execution without waiting until the logs are really received by grafana. Therefore the logs are highly unlikely to get to grafana leaving me without a knowledge about what exactly happened.

Currently I have to do something ugly like the following to ensure the logs appear in grafana:

(async ()=>{
  logger.log('info', "Error happened");
  await delayMilliseconds(5000);
  process.exit(0);
})();

But that's ugly and may not work if the network is slow and/or grafana requires more than 5000 milliseconds to get and process the logs.

A better fix for this issue is in the patch attached. After applying the patch to winston-loki today's development HEAD the code can be changed to the following to get the desired behavior:

(async ()=>{
  logger.log('info', "Error happened");
  await loggerTransport.flush();
  process.exit(0);
})();

The line await loggerTransport.flush(); does exactly what is written in jsdoc in the patch. It waits until all logs "queued" before (by calling logger.log() or similar) are sent to grafana, the responses are received and processed by winston-loki, and only then continues execution. By the time of process.exit(0) call grafana has RESPONDED winston-loki that all the logs are received and stored.

After investigating winston-loki sources I would say it's the best solution technically possible. Tha patch works correctly with batching both turned on and turned off.

Could you please consider applying the patch upstream and making a release including it?

winston-loki-flush.patch.gz

@pv4
Copy link
Author

pv4 commented Jan 13, 2023

Hmm... this issue seems to be a copy of #120. But this one has a patch. Besides, the solution suggested in #120 may not work properly sometimes if connection or grafana are slow or if batching is off.

@GiancarlosIO
Copy link

+1
We are also having this issue where the node process ends before the log is sent to graphana 😢

@JaniAnttonen
Copy link
Owner

Thanks for the patch, and sorry for the delayed response. :) Released this patch under the @next tag, version 6.0.7-rc2.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants