Many of Heroku's internal components make heavy use of logfmt to log information about what's going on in production. The format is hugely valuable in that it allows us to retroactively analyze what happened during any arbitrary request to our components, query our log traces in very flexible ways, and combined with Splunk, easily generate arbitrary metrics on historical data. It's unquestionably been an invaluable tool for fixing countless bugs, tracking down the root cause of many production incidents, and assessing usage in ways that would have been difficult otherwise.
That said, when viewed in the wrong light, logfmt is capable of producing hard-to-read walls of text like nothing else, which can be slow for a human to parse and even more difficult to visualize. The wall of text below for example, represents a standard fulfillment from the build API and is a whopping 51 pages long:
To make exploring this data a slightly less onerous task, we've written a tiny suite of tools called "hutils" that are installable via Rubygems:
gem install hutils
See the README for full details on the usage information, but a few of the more important tools in hutils are:
ltap: Extracts a message stream from either Splunk or Papertrail based on an input search query, like for example, a request ID. The stream is dumped to stdout for analysis or processing by other tools.
lviz: Parses a set of log messages to build a tree where ancestors represent the largest possible sets of common key/value nodes for all of their descendants, which usually has the effect of pruning a huge amount of duplicate data. This tree is then displayed on the terminal in an attractive way.
As dictated by the philosophy of small, sharp tools described in The Art of Unix Programming, tools from the suite are designed to be chained together to augment their usefulness. Combining
lviz looks something like this:
ltap "95a89bef-ff65-49c8-95a6-fbc0fbeca8cd earliest=-1d" | head -n 50 | lviz
And the ugly Splunk trace above is transformed into something a little more digestible:
lviz also ships with a
--compact option if the output above is too verbose for your taste.
Hutils also ship with a few other commands to help work with logfmt:
lcut: For selecting fields from a logfmt stream. Also suitable for use with
heroku logs --tail.
lfmt: Prettifies a logfmt stream with colors, whitespace, and custom highlights. Also suitable for use with
heroku logs --tail.
Give it a try today and if you have any requests or want to contribute then check out the project on github