Figure out how to get logs in a format for Graylog (loggins)

[cmcavoy]

Winston graylog transport

[toolness]

This is analogous to mozilla/CSOL-site#569, I think... Whatever the solution to that ticket ends up being should also apply to this one. Please correct me if I'm wrong though.

[brianloveswords]

Sounds right to me.

[cmcavoy]

Correct...and we should also apply it to Aestimia. 15% more robust.

On Tue, Jun 11, 2013 at 1:37 PM, Brian J Brennan notifications@github.comwrote:

Sounds right to me.

— Reply to this email directly or view it on GitHubhttps://github.com/mozilla/openbadger/issues/217#issuecomment-19283200 .

@chmcavoy http://twitter.com/chmcavoy http://lonelylion.com

[brianloveswords]

Okay, here's the strategy:

Step 1: Use bunyan for structured JSON logging

We inherited the choice to use winston from the fact that openbadges was originally cloned from the browserid codebase and that's what they were using. It's served us well across several projects so far, but I think it's time to part ways. The transport system is confusing and we only want to output to stdout/stderr anyway – saving logs to disk is so 2003.

On that note, bunyan seems pretty rad – http://blog.nodejs.org/2012/03/28/service-logging-in-json-with-bunyan/. It's fairly simple and designed for spitting out structured logs.

(NOTE: winston does have a JSON transport, but bunyan has other benefits which I will touch on below)

Step 2: GELF it up..

Right now our method of getting logs into Graylog2 (a.k.a loggins) is to pump them through syslog and send all of the syslogs to loggins. There are some limitations here:

1. Multiple lines get split up into different entries. This makes stack traces come in as a bunch of different entries in reverse order which is stupid.
2. Syslog has a hard limit of 1024 bytes per entry. So even if we jammed all of the stack trace into one message, there's a very real chance that parts of it would be cut off.

In light of that, Graylog created the Graylog Extended Log Format, a lightweight JSON based log format designed to be sent over UDP.

Step 3: ...through the magic of stdout/stderr streams

While GELF is awesome for getting structured logs into graylog, I don't want to have log-endpoint specific stuff in our apps – it makes them less able to be redeployed if someone wants to use some other log aggregator.

My proposed strategy is to pipe stdout from the app to small utility that converts the structured JSON log stream into a GELF stream and sends it off to loggins. We can use https://github.com/mhart/gelf-stream (which has native support for bunyan) or https://github.com/robertkowalski/gelf-node (which is dead-simple).

Considerations

• It will still be important to use a process.once('uncaughtException') handler to convert stack traces to structured logs before crashing (note: we should definitely still crash because the app will be in an unexpected state).
• JSON logs might be hard to read in development. I think with pretty-printing, it won't be so bad, and any logging for debugging purposes can be done with temporary console.logs. We could also always write another small utility to convert the structured log stream into a human readable stream and pipe through that for dev. We could also only add the uncaughtException listener when NODE_ENV=production so we get raw stacktraces in development.
• The conversion utilities need to be fault tolerant – errant console.logs, other non-JSON data and fragmented JSON should not screw it up. This is probably my biggest concern, and I'm willing to revise my strategy if this becomes a problem.