How To Write Good Log Messages • Hacker News Board

Re: How To Write Good Log Messages

#21

Post by sarabob » Thu, Aug 09, 2012, 9:32 PM UTC

jamesaguilar wrote: post #11

Most important point: any log message that doesn't identify some property of the request that originated it (so that you can identify requests leading to erroneous conditions) is cause for immediate defenestration.

Agreed. We use mod_unique to add a header to each response and make sure it's included in each error log, back end access log and front end access log as well as being viewable via Charles/fiddler at the client. Being able to tie the various logs from different machines together has been invaluable.

Re: How To Write Good Log Messages

#22

Post by gbog » Thu, Aug 09, 2012, 9:35 PM UTC

mgurlitz wrote: post #9

memset wrote: post #7

I personally have found a lot of difficulty with JSON-based logs, because tools like `grep` and `cut` don't suffice; I usually have to write a more complex regex with `sed` in order to extract useful information I want. Anyone have a good utility for managing JSON in log files?

Moving away from using regex to parse JSON, you can use Jsawk and Underscore-cli to manipulate JSON like Awk or JavaScript. https://github.com/micha/jsawk/ https://github.com/ddopson/underscore-cli

But the problem is speed. I found that if parsing logs is slow, bug hunting is far less efficient.

Re: How To Write Good Log Messages

#23

Post by jcrites » Thu, Aug 09, 2012, 9:47 PM UTC

memset wrote: post #7

I personally have found a lot of difficulty with JSON-based logs, because tools like `grep` and `cut` don't suffice; I usually have to write a more complex regex with `sed` in order to extract useful information I want. Anyone have a good utility for managing JSON in log files?

RecordStream is a great solution for manipulating JSON log files: https://github.com/benbernard/RecordStream - makes it easy to perform relational-style operations, such as grouping, counting (recs-collate), and even joins (recs-join). It can also display and transform the logs in a variety of ways (recs-tocsv, recs-totable, recs-tognuplot for graphing).

There are also tools to extract records from other data formats such as CSV or by querying a database.

All in all, a fantastic tool for manipulating and querying complex data from the command line. I use it regularly.

Re: How To Write Good Log Messages

#24

Post by Pfhreak » Thu, Aug 09, 2012, 10:01 PM UTC

[deleted] wrote: post #18

shazow wrote: post #17

"08-08-2012-20:27:59" Which 08 is the day or the month? cut -d ' ' -f2- foo.log | sort Great, now it's sorted by (month, day, year) or (day, month, year). If my logs span multiple years, the sorting is useless. Please use YYYY-MM-DD. It's sortable and more intuitive for everyone outside of the USA. See also http://en.wikipedia.org/wiki/ISO_8601

[deleted]

Still doesn't solve the sorting problem. YYYY-MM-DD produces sortable strings without needing to parse them.

Re: How To Write Good Log Messages

#25

Post by Jimbotron » Thu, Aug 09, 2012, 10:07 PM UTC

In my experience the measure of good logging is the ability for someone, either yourself or an operations engineer to be able to easily solve problems using only the logs. They shouldn't have to refer to the source code. Developers should be using this as the yardstick when asking questions about their log output.

Re: How To Write Good Log Messages

#26

Post by Pfhreak » Thu, Aug 09, 2012, 10:07 PM UTC

UTC is great for timestamps, but he needs to make his times sortable (YYYY-MM-DD) Tab delimited fields are a problem, unless you escape the tabs inside the data you log.

This format seems VERY similar to the Graylog Extended Log Format (or GELF) https://github.com/Graylog2/graylog2-docs/wiki/GELF

I'm a huge fan of JSON logs now, having just finished implementing them on a major work project. Every language out there can take JSON in and do work against it, and there are some really awesome tools for rendering filtered logs to a browser in realtime.

Re: How To Write Good Log Messages

#27

Post by mseebach » Thu, Aug 09, 2012, 10:25 PM UTC

Pfhreak wrote: post #26

UTC is great for timestamps, but he needs to make his times sortable (YYYY-MM-DD) Tab delimited fields are a problem, unless you escape the tabs inside the data you log. This format seems VERY similar to the Graylog Extended Log Format (or GELF) https://github.com/Graylog2/graylog2-docs/wiki/GELF I'm a huge fan of JSON logs now, having just finished implementing them on a major work project. Every language out there…

> Tab delimited fields are a problem, unless you escape the tabs.

I don't understand this? A tab is a tab?

> JSON

Downside: File size. If you have any appreciable level of traffic/activity this matters.

Re: How To Write Good Log Messages

#28

Post by mseebach » Thu, Aug 09, 2012, 10:31 PM UTC

dinkumthinkum wrote: post #15

trotter_cashion wrote: post #6

Earlier quoted context omitted.

Thanks for the feedback. I'm with you on the milliseconds and threads bits. As for hostname / version... how are you getting those into your logs? I've found having version in the logs very useful (and wished I had it when it wasn't there).

I don't think outputting the version is overkill at all. It's much easier and simpler to deal with it this way. Probably the nanosecond business is very much overkill, that only matters for a smaller subset of problem domains.

Whether the version is overkill depends on the frequency of version changes. If you're doing careful corporate releases with staging and QA on a two-month basis, it's definitely overkill - if you're doing continuous deployment with several releases daily and different systems running different versions concurrently, it's probably valuable.

Re: How To Write Good Log Messages

#29

Post by eru » Thu, Aug 09, 2012, 10:41 PM UTC

cluda01 wrote: post #14

pacaro wrote: post #12

Earlier quoted context omitted.

This. UTC is not only unambiguous, but on some systems measurably faster to capture. My experience has taught me to work in UTC everywhere possible, local time is typically only relevant for direct human interaction.

A caveat here as well is you also need to make sure your various clocks in the data center are synched. This is one of those common but overlooked scenarios which lead to hilarious discussions about latency when really there was just a clock synch problem. Additionally the fallacies of distributed computing come into play here (namely, transport cost is 0) so you need to take extra care when looking at measurements a…

Yes. But you get all those problems plus more, if you convert to local time first.

Re: How To Write Good Log Messages

#30

Post by eru » Thu, Aug 09, 2012, 10:43 PM UTC

trotter_cashion wrote: post #16

pydave wrote: post #13

Earlier quoted context omitted.

Couldn't you output the host and version at the beginning of the log? Any tool that transforms the logs (splicing together logs from different servers) should include these bits in it's output. Also, why don't you use a sortable form for time? (With the most significant parts first.)

My issue with host and version at the beginning of the log is that they'll roll away when your logs rotate. If you've got a service that's rarely taken down, anything written to the front of the logs is likely long gone by the time you have a problem. That said, there may be a better way to handle these two. I certainly don't like repeating information if it's not necessary.

> I certainly don't like repeating information if it's not necessary.

On what grounds?