Unhandled exception if fluentd instance dies in the middle of queue flushing about fluent-logger-node HOT 12 CLOSED

Could you try #84 ?

Is this easy to reproduce?
I could not reproduce this issue in my local environment.

from fluent-logger-node.

@okkez yeah, it's not reproducable locally for me as well, happens from time to time on production...

I did a quick check of the patch, but I don't think it will work properly, when you go through _pendingPackets and try to write everything inside, upon error you will add the packet again into array, so there will be multiple packets. I also don't see where the array is flushed

from fluent-logger-node.

Thank you for checking patch.
I will take time for this issue in next week.

Could you tell me following points?:

• how many logs per second?
• log size
• and more about your production

from fluent-logger-node.

@vgoloviznin

I also don't see where the array is flushed

Flush _pendingPackets here

from fluent-logger-node.

@okkez working on answering the questions of yours!

As for flushing, I don't see that items are removed after\during the foreach

from fluent-logger-node.

how many logs per second?

~100 per second

log size

Quite heavy, ~1-2kb each

and more about your production

We observed this issue at least 3 times within the following scenario:

0. Fluentd has ES as a back-end store.
1. ES due to capacity-throughtput reasons dies with OOM.
2. Fluentd starts buffering log events in RAM, waiting for ES to come back.
3. Fluentd RAM buffer is exhausted, so it starts emitting a ton of exceptions in log (https://gist.github.com/shuttie/fa467d80425887a4e81987dafa6c0271)
4. And after that fluent-logger-node starts pooping with errors as described earlier, breaking our prod.

from fluent-logger-node.

Thank you for describing scenario! @shuttie

from fluent-logger-node.

Solution (improve Fluentd robustness):

• fluent-logger-node
  • (optional) enable requireAckResponse
• Fluentd
  • use file buffer (not memory)
  • increase buffer size limit if needed, see https://docs.fluentd.org/v0.14/articles/buffer-section#buffering-parameters
  • use secondary output to store logs when ES is down

from fluent-logger-node.

I'm also seeing this stacktrace, when the FluentD server is unavailable. Shouldn't the code at https://github.com/fluent/fluent-logger-node/blob/master/lib/sender.js#L360 check if this._socket is set before trying to dereference it?

Console output:

Fluentd will reconnect after 60 seconds
Fluentd error { Error: write EPIPE
     at _errnoException (util.js:1024:11)
     at WriteWrap.afterWrite (net.js:867:14) code: 'EPIPE', errno: 'EPIPE', syscall: 'write' }
TypeError: Cannot read property 'write' of null
    at FluentSender._doWrite (/code/node_modules/fluent-logger/lib/sender.js:360:16)
    at FluentSender._doFlushSendQueue (/code/node_modules/fluent-logger/lib/sender.js:334:10)
    at process.nextTick (/code/node_modules/fluent-logger/lib/sender.js:390:14)
    at _combinedTickCallback (internal/process/next_tick.js:131:7)
    at process._tickDomainCallback (internal/process/next_tick.js:218:9)
[nodemon] app crashed - waiting for file changes before starting...

from fluent-logger-node.

I can confirm the issue reported by @mcuelenaere in HEAD. Stopping the
fluentd server under a heavy load will result in an uncaught exception
in the client.

For now, fluentd-logger-node consumes the message queue as follows:

1: _connect()
2: _flushSendQueue()    // Check if the socket is available
3: _doFlushSendQueue()  // Take the first message from the queue
4: _doWrite()           // Send it.
5: _doFlushSendQueue()  // Take the second message from the queue.
6: _doWrite()           // Send it.
7: ...                  // Repeat until the queue is empty...

The problem is that, while the socket might be closed (asynchronously)
after the first write, _doFlushSendQueue and _doWrite naively assume
that the socket is always available. So if the socket gets closed
somewhere after the step 4 above, the logger client will just crash.

The pull request #90 is my attempts to fix this issue by adding a bunch of
checks on the related part.

from fluent-logger-node.

@mcuelenaere Could you try the PR #90?

from fluent-logger-node.

Merged #90 and released v2.6.2 .

from fluent-logger-node.