ovhemert/pino-papertrail

Stopped logging after loosing connectivity to papertrail

mattiash opened this issue ยท 2 comments

๐Ÿ› Bug Report

My service was running and logging with pino to stdout. The stdout is piped to pino-papertrail.
My internet connection died and pino-papertrail could no longer submit logs to papertrail.

pino-papertrail logged the following to stdout:

events.js:174
      throw er; // Unhandled 'error' event
      ^

Error: getaddrinfo EAI_AGAIN logs7.papertrailapp.com
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:56:26)
Emitted 'error' event at:
    at errorOrDestroy (internal/streams/destroy.js:107:12)
    at Pumpify.onerror (_stream_readable.js:734:7)
    at Pumpify.emit (events.js:198:13)
    at Pumpify.Duplexify._destroy (/usr/local/lib/node_modules/pino-papertrail/node_modules/duplexify/index.js:195:15)
    at /usr/local/lib/node_modules/pino-papertrail/node_modules/duplexify/index.js:185:10
    at process._tickCallback (internal/process/next_tick.js:61:11)

After this pino-papertrail did not forward any logs to stdout and it did not log anything to papertrail.

After a few minutes, my internet connection was restored. pino-papertrail did however not resume logging to papertrail and it did not resume logging to stdout either.

Some hours later, I restarted my service and pino-papertrail and then logging started working again.

Expected behavior

I would have expected pino-papertrail to continue logging to stdout the whole time, regardless of if it could forward logs to papertrail or not. I would also have expected it to resume logging to papertrail when internet connectivity was restored.

Your Environment

  • os: Linux
  • node 10.20.1

The "problem" is that pumpify uses pump, and the documentation for pump explicitly says:

Combine an array of streams into a single duplex stream using pump and duplexify. If one of the streams closes/errors all streams in the pipeline will be destroyed.

I looked at the code in this module and came up with the following patch:

diff --git a/lib/pino-papertrail.js b/lib/pino-papertrail.js
index 0931f6a..efaedbf 100644
--- a/lib/pino-papertrail.js
+++ b/lib/pino-papertrail.js
@@ -86,7 +86,10 @@ function toPapertrailUdp (options) {
     write (data, encoding, callback) {
       if (options.echo === true) { console.log(data.toString()) }
       socket.send(data, 0, data.length, options.port, options.host, function (err) {
-        callback(err)
+        if(err) {
+          console.log('error', err.message)
+        }
+        callback()
       })
     }
   })

What it does is to not pass the err value to the callback, i.e. just swallow all the data and don't report an error to the callback even if it fails to send the data to papertrail. I think this is an acceptable behavior, since we are using udp anyway and that does not give any guarantees about delivery.

With this patch, pino-papertrail will log an error while DNS lookups fail and then resume sending data to papertrail when DNS lookups work again.

My question is if this is an acceptable approach to you and what I should do with the error. Just logging it to stdout seems reasonable to me.

LGTM,.. feel free to send a PR