Logging can be tricky
11–20 of 77 posts
Re: Logging can be tricky
#12Turns 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
#13Wow...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.
Re: Logging can be tricky
#14Doe 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…
Re: Logging can be tricky
#15Grey text on white background? Please help!
Re: Logging can be tricky
#16Reminds 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
(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
#17Compressing 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.
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
#18Why would you fsync logs for a high-level service? Are you afraid a power outage is going to cause you to lose service logs?
Say, if you hit a bug somewhere that causes the server itself to crash.
Re: Logging can be tricky
#19When 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
#20Reminds 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…