Live data from Hacker News

How To Write Good Log Messages

trottercashion.com

31–40 of 57 posts

Re: How To Write Good Log Messages

#31
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.

They should compress well.

Re: How To Write Good Log Messages

#32
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

To go one step further...

RFC3339 gives a more tightly defined subset of ISO8601, which is even more useful and lacking things like "week of year" which have little use on modern systems:

http://tools.ietf.org/html/rfc3339

Re: How To Write Good Log Messages

#33
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.

You could just print the version, etc. again when logrotate sends your daemon a SIGHUP.

Re: How To Write Good Log Messages

#34

One of the hardest things in ops is trying to see what the app is doing without benefit of the code to review. I know what the app does, I know the process flows involved but 'failed to covert X at MyClass:44' doesn't have enough context for me. Also log levels - most developers over use warning and error levels and under uses debug and trace in my experience. It makes filtering out the noise harder. Rolling log file…

Lastly stack traces, if they even have a use case at all in production, should not be in the main logfile.

I would have to disagree with this one. There's no way to generate the stack trace after the fact if a particular bug is extremely rare; having a complete call chain makes fixing the problem much easier.

Someone once said that removing error handling once the code is working is like removing the landing gear once a plane is airborne.

Re: How To Write Good Log Messages

#35
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.

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

How do you differentiate between tabs that the logger generates, and tabs inside log messages? You need to escape the tabs inside messages. This problem exists with any character delimited format (e.g. csv).

Re: How To Write Good Log Messages

#36
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.

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

I think the parent meant that a problem could be if data itself contains a tab character, causing an offset during parsing.

Re: How To Write Good Log Messages

#37
post #31

Earlier quoted context omitted.

> 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.

They should compress well.

In fact, they compress to about a 3% of their size. Since they really only exist in text file form for a limited period of time before being moved on to a separate logging system, their exploded size isn't much of a concern.

Re: How To Write Good Log Messages

#38
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?

Recs (therecordstream.com) is great for this. A JSON log file would be interpreted as its native record format, so you can use all of its processing tools (like recs-grep and recs-collate and recs-sort).

Re: How To Write Good Log Messages

#39

One of the hardest things in ops is trying to see what the app is doing without benefit of the code to review. I know what the app does, I know the process flows involved but 'failed to covert X at MyClass:44' doesn't have enough context for me. Also log levels - most developers over use warning and error levels and under uses debug and trace in my experience. It makes filtering out the noise harder. Rolling log file…

I always use warning to indicate something actionable for the developers. Some condition they should add to their next sprint, for example.

An error is something actionable that needs to be responded to soon. You probably don't need to send a page, but an error is a serious condition.

Stack traces are extraordinarily useful in your logs. When code breaks (and it will), you want as much information surrounding that event as possible.

Re: How To Write Good Log Messages

#40

One of the hardest things in ops is trying to see what the app is doing without benefit of the code to review. I know what the app does, I know the process flows involved but 'failed to covert X at MyClass:44' doesn't have enough context for me. Also log levels - most developers over use warning and error levels and under uses debug and trace in my experience. It makes filtering out the noise harder. Rolling log file…

roll on an event (new day, process bounced etc.) not on reaching a 10Mb limit

Only applicable when you produce a small, predictable volume of logging. Not a good general guideline because often you don't know how big your system may grow in the future.

When logging high volumes then fixed chunk sizes are usually preferable (e.g. so you know how many you can keep around without a disk running full). Large sites produce multiple gigabytes of logs per hour.

Use a header in the logfile

Disagree. Context should be provided directly in each individual line. Logs get sliced and diced in analysis, fetching an arbitrary header from the right file for a given context can be rather painful.

Don't be afraid of long lines. Use field delimited formats (TSV) so they can be easily parsed (either via 'cut' or a small script).

stack traces ... should not be in the main logfile

Wrong. When a serious error occurs then as much context as feasible must be provided. Stack traces are usually very feasible and indispensable.

Post reply on HN