Live data from Hacker News

Logging can be tricky

corner.squareup.com

11–20 of 77 posts

Re: Logging can be tricky

#12
I had a similar problem with java -- except that the entire application would freeze for double digit seconds. Another application would sometimes write a huge amount of data out very quickly to the fs cache. 30 seconds later (or w/e the expiration is), all those dirty bytes would get sync'd to disk more or less at once.

Turns out it was the JVM provided GC logging hanging on flush (not even fsync) calls. The flush call was during GC, and while the GC implementation held a stop the world lock. Digging through JVM source code is 'fun'.

Re: Logging can be tricky

#13

Wow...this post made me think I shouldn't even attempt to run my own server infrastructure for my startup. This kind of analysis is way deeper than I'm currently capable of.

Unless you're really unlucky/using young tech/bad at programming you won't need that kind of expertise unless you have the kind of traffic which means you can afford to hire that expertise.

Re: Logging can be tricky

#14
post #6
post #5

Doe this increase the chance that you lose a bit of critical log if a fault causes the system to go down?

Yes, but if the logs are just for debugging an application, it usually doesn't matter. Application logs are useful for figuring out why an application crashed, but shouldn't be relevant for figuring out why a system went down. However, if the app crashes while some log information is still in the system buffers, the system will still write them out, even if fsync() is never called. It's been a few years since I looke…

Also if your logging plugin / framework / module allows logging to remote syslog, that's a pretty good idea - no disk blocking. Although you are then risking data loss when the network goes down...

Re: Logging can be tricky

#16
post #10

Reminds me of the time I sped up the main business app of a large company by 85% by removing "debug" logging. 2tb/hr of "made it here" isn't really useful at the end of the day. Not the first time I've seen that by a long shot. //shakes zimmerframe, shuffles off

Thus why your logging library should have a configurable log-level, and the first thing the user-facing log() function should do is check the arguments against the log-level and early-return if the message isn't important enough.

(In languages that support macros, you could also just make debug_log() a macro that gets compiled out on release builds, like assert(). That means a whole bunch of object files are going to be functionally different between debug and release builds, though, which is annoying for a lot of operational reasons.)

My favourite solution by far, though, is the one recently implemented by Elixir: log() is a regular function, but takes a closure instead of a string. That way, you can actually put all the work required to generate the log message (inspecting data structures, doing intermediate lookups, etc.) inside the closure, and it all gets elided when you decrease the log-level.

Re: Logging can be tricky

#17
post #3

Compressing the text logs prior to writing them to the disk also helps with these kinds of issues. You can also offload your logging to a dedicated thread and then use a lock free queue to increase your performance even more.

> You can also offload your logging to a dedicated thread and then use a lock free queue to increase your performance even more.

Or use syslog() like a sane person, and let that "extra thread" live inside the OS IPC mechanism.

(Or stdout/stderr like a modern sane person, and let upstart/systemd/docker/etc. push your logs to syslog if that's where it feels like pushing them.)

Re: Logging can be tricky

#18
post #9

Why would you fsync logs for a high-level service? Are you afraid a power outage is going to cause you to lose service logs?

Making sure your logging data gets written is relatively important.

Say, if you hit a bug somewhere that causes the server itself to crash.

Re: Logging can be tricky

#19
If all three machines had the same logging code, and one machine was fsync'ing slowly, isn't turning off fsync just a bandaid that hides the true problem?

When they discover the actual problem is some issue with the raid controller, I promise not to say "I told you so".

Re: Logging can be tricky

#20
post #16
post #10

Reminds me of the time I sped up the main business app of a large company by 85% by removing "debug" logging. 2tb/hr of "made it here" isn't really useful at the end of the day. Not the first time I've seen that by a long shot. //shakes zimmerframe, shuffles off

Thus why your logging library should have a configurable log-level, and the first thing the user-facing log() function should do is check the arguments against the log-level and early-return if the message isn't important enough. (In languages that support macros, you could also just make debug_log() a macro that gets compiled out on release builds, like assert(). That means a whole bunch of object files are going to…

Enclosed log evaluation is really nice and I'd have some trouble going back. It's older than Elixir, too; Commons.Logging in C# has supported it for a long time and most logging frameworks in Scala take a call-by-name parameter rather than an evaluated arg.
Post reply on HN