Software Logging Schemes? 225
MySkippy writes "I've been a software engineer for just over 10 years, and I've seen a lot of different styles of logging in the applications I've worked on. Some were extremely verbose — about 1 logging line for every 2 lines of code. Others were very lacking, with maybe 1 line in 200 devoted to logging. I personally find that writing debug and informational messages about every 2 to 5 lines works well for debugging an issue, but can become cumbersome when reading through a log for analysis. I like to write warning messages when thresholds or limits are being approached — these tend to be infrequent. I log errors whenever I catch one (but I've never put a 'fatal' message in my code, because if it's truly a fatal error I probably didn't catch it). Recently I came across log4j and log4net and have begun using them both. That brings me to my question: how do the coders on Slashdot handle logging in their code?"
Three levels (Score:3, Interesting)
I find I usually end up with 3 levels of logging:
Normal operation, often with some notion of "Yes, I'm still running even though I haven't done anything else lately".
Details. Usually corresponding to processing steps.
Algorithm tracing. This includes things like logging SQL queries. This is usually only of interest to me.
...laura
It varies (Score:3, Interesting)
I will add lots of logging to debug a specific problem and then rip it out when the problem is fixed. Permanent logging includes run time problems like serial communication errors, file not found, etc. I like to make various logging functions switchable, so user input can be logged for example, but only when needed. Once a program is running well, it should only log data for dire exceptions, unless regular accounting logs are needed.
whatever you do, don't use nfs (Score:5, Interesting)
If you're using log4j, don't use multiple hosts to write to the same nfs filesystem file. You'll run into blocking issues and log4j doesn't handle them correctly. The nirvana of clustered app logging is an async JMS queue. You fire off the message and forget it. You don't wait for file handles.
Depends on the application you're writing (Score:2, Interesting)
Re:Logging to a database (Score:3, Interesting)
TOO MUCH! (Score:3, Interesting)
1 line of logging per 200 lines of code is way too much. 2 in 5 lines is absolutely insane. I've seen way too many systems where the logging made it totally unusable. People just don't realize the costs of logging everything.
There's absolutely no way to document anything this verbose. Without documentation, the logging is useless.
Re:youre doing it wrong (Score:2, Interesting)
Comment removed (Score:3, Interesting)
Filters (Score:3, Interesting)
I asked slashdot a very similar question (Score:2, Interesting)
LVL1 - basic startup and shutdown info ( a few lines per run)
LVL2 - Interactions with the database
LVL3 - Interactions with the file system
LVL4 - Detailed database interactions including each sql statement
LVL5 - amazingly verbose debug information including memory and variable allocations
In almost all cases, I recommend being able to set each level on or off. Your sysadmin (maybe yourself) will appreciate that ability.
If appropriate, I recommend an 'audit' record after each completed or aborted transaction. EG - after every order or every user change or whatever is important for accountability / business activity monitoring purposes.
This is the original question [slashdot.org] .
Re:youre doing it wrong (Score:3, Interesting)
There is no code in the world that I can think of that needs a log line after every two steps in a procedure.
Any code in which timeouts can affect the result would require this kind of logging, which includes networking code or code that handshakes between multiple threads/processors. Example: debugging something like a new x/y/zmodem implementation is nigh impossible within a debugger because your side must respond within 10 seconds or the other side will start acting differently.
Re:not cpu bound... disk bound (Score:2, Interesting)
Companies with virtualized machines are often also using storage area networking and related high-availability technologies. The traditional bottleneck associated with disk I/O does not happen nearly as badly.
Re:As little as practically possible (Score:3, Interesting)
Be careful what you log... (Score:4, Interesting)
It might come back to haunt you later.
Re:As little as practically possible (Score:3, Interesting)
And let's hope it never does disappear or we can kiss new software goodbye.
None Inline, Use AOP (Score:5, Interesting)
That being said, you can add what ever logging you want as long as you do it outside the application code, such as through AOP (if you don't know what that is then google is your new best friend).
Logging through external means has a number of benefits. First you application code is relieved from unnecessary clutter. Second the logging can be added or removed as fit for the environment with no need for any runtime checking, which is perfect for turning of all logging in production environments. And lastly it enforces good coding practices as it makes sure people break up code in a way that makes external logging possible, which is how code should be written anyway.
The majority of all logging, dare I say all useful logging, is easy to summarize.
This is perfect for function/method interception since it comes down to something more specific.
So simply add the first logging to an interceptor that operates before the functions you want to log, and the second after the function.
If you find yourself needing detail inside the function then you need to break the function up into sub routines, so you can use this generic logging on the sub routines instead, or as well as.
Re:not cpu bound... disk bound (Score:2, Interesting)
Re:As little as practically possible (Score:3, Interesting)
I wonder why, given the huge increase in the performance of computers over the last ten years and more, why it sill takes some games one to five minutes to load.
The goal of almost any commercial product isn't to be 100% awesome in every possible way. It's to be adequate on most measures and awesome in the few that buyers care most about.
Game buyers care about volume and quality of content a lot more than load time. So even if some engineer figured out a way to cut load time in half, somebody would just add more content and bump up bit rates and quality levels until it was back to a tolerable load time.
Re:taking it a big further - no logging at all (Score:5, Interesting)
I just had occasion to try and optimize an old C++ app that was having performance issues in certain sections. This app had its own custom logging system using Unix message queues, and was always a little suspect. I noticed as I tried to instrument the code that whenever I seemed to get close to the bottleneck, the problem seemed to move to a different part of the code. Finally, it dawned on me that the log system itself was part of the problem. In fact, the log object constructor was taking significant time, including (in some places) within critical (as in lock/unlock) sections. Most critical classes had been defined with an instance of the logger as a member, which was overkill. Doing nothing more than changing the definitions of the log objects to static dropped critical section performance by an entire order of magnitude.
Moral: Do logging, but do it judiciously. Know what you're doing - and know what the log system is doing too.