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?"
Re:As little as practically possible (Score:5, Insightful)
"Otherwise don't do much logging because it will hurt application performance, sometimes drastically."
You're assuming that performance -- or, more precisely, CPU usage -- is important; in many cases, reliability (and being able to track down bugs after a crash) are far more important than CPU usage. With quad-core CPUs so cheap these days, we can easily afford to spend another thousand dollars to throw more processing power into a system which has cost a couple of hundred thousand dollars of programmer time to develop and will cost thousands of dollars an hour for any downtime.
taking it a big further - no logging at all (Score:4, Insightful)
Don't coddle weak programmers... it's survival of the fittest out here. Either they learn to nourish themselves from the ample teat of a stack dump, or they must perish. It is for the good of our civilization. I know this seems harsh, young Jedi, but it is the way of the Elders of Assembler, from the ancient Time Before OO. Now go Forth and code.
Okay, joking aside. Parent has a great point -- logging can generate incredible volumes of text and can form a remarkable bottleneck, especially on VM systems where your OS may not be the only one hitting the disk.
So take advantage of Log4J/Net's ability to log at different severity levels and make logging globally configurable so you can enable/disable entirely at runtime. I'd recommend you log the following : object creation, scarce resource allocation, recoverable failure/error conditions and unrecoverable failures. Preface each severity level with a unique label so you can grep for it later. Even at the most verbose level, you can then grep your output to see only what's of interest to you (e.g. "unrecoverable:...").
not cpu bound... disk bound (Score:5, Insightful)
It's not CPU that's at a premium, it's disk IO. And on virtualized machines (such as is extremely popular in corporations and hosting farms) where there might be four different OSs running on the same physical hardware, disk becomes a scarce resource very, very quickly. And not only does your virtualized server go to shit, it takes the others down with it since they can't get timely disk access, either.
Re:Logging to a database (Score:4, Insightful)
Not to mention the added complexity and failure modes. All but the most trivial databases can go wrong in interesting ways, and when that happens where will you put your logging? It's precisely when things go wrong that you need logging the most. So you want the least possible dependencies. Right now, that's appending text to a file - file systems are simpler and tested more thoroughly than even the best databases can be.
Like the user (or the system, or the virus...) shutdown the database server in the middle of operation. How do you prove that after the fact if the logs were going into the database?
Re:As little as practically possible (Score:5, Insightful)
I work on a real-time embedded medical device, where both performance and reliability are vital. We've got constrained resources, and the system must be extremely responsive.
Our logging scheme is pretty cool. It's written so that two computers can log to a single hard drive, and each logging statement must define a log level. So, for example, if I'm writing GUI code, I can log to log_level_gui_info, log_level_gui_debug, log_level_gui_error, or any of a number of more specific log levels.
The idea is
So, we have two ways to filter out extraneous logging that we don't care about (one actually keeps the logging from happening, and one just filters it out during analysis), and we can log as freely as we like as long as we're smart about which levels we're using.
As much faith as we all have in our own code, nothing's as frustrating as trying to analyze a log that came in from the field where there's just no information about what went wrong.
Re:Whatever is useful while programming. (Score:3, Insightful)
Re:As little as practically possible (Score:2, Insightful)
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... one reason I am more likely to play spider solitaire now when I just want to play something for 10 or 15 minutes. Anyway... it is this kind of attitude causing it (e.g. "Screw it... we have good CPUs and lots of memory... who gives a shit if I don't feel like considering performance"). If people would program things as efficiently now as they did in years past, performance tuning analysts would be out of work, the enterprise systems I see being build now wouldn't be sucked out performance dogs out of the gate, games would be more fun, etc. etc. etc. etc.
ok... I feel better now...
As much as practically possible (Score:5, Insightful)
On the other hand, broken code hurts application performance, sometimes drastically.
I'm an SQA engineer with years of experience working with large scale enterprise systems. Generally speaking the cost of unexpected outages or data corruption outweighs the cost of hardware. In such systems the costs of deployment activity itself can be such that you'd rather pay for more hardware to support extremely verbose logging.
Sure, boneheaded logging can cause unnecessary performance hits, the obvious example being logging in a loop when logging at entry and exit would have sufficed. But that's not what we are really talking about here. You posited that you should do as little logging as practically possible, and I believe that you are wrong.
Log lots and log often. Just do so intelligently. Use a logging framework (log4j, log4net, log4perl etc) and set the priority appropriately. Only use ERROR for real errors (unexpected code paths or data), use WARN when a performance metric is hitting a soft limit (to warn you before you hit that hard limit), and use DEBUG to verbosely log anything else of general interest. Rarely you might also want to log in an extremely verbose manner data that wouldn't ordinarily be interesting, and this should be logged at a TRACE level. Generally speaking if this is the case then the code itself is due for a refactor. FATAL should normally be reserved for errors that prevent correct startup - generally if an application runs correctly at startup then any potential faults that you see and handle now become ERRORs because there is nearly always something better an application can do than log FATAL and exit. As the OP observed, if you have a potential fault that kills your application and you don't see and handle it then you don't have the opportunity to log FATAL anyway.
By using a logging framework, many logging pitfalls can be avoided because the framework itself provides well tested facilities. eg, time-stamping, log rotation, file-handle management etc. In addition, using a framework allows the operator to tune the logging on a very granular level. This allows for a trade off to be made where if a performance impact is noted in a well used class then its logging can be reduced at runtime. Sure, there is still a small performance impact because the logging framework has to do a "if (logMessage.logLevel >= loggingClass.logLevel ) then {...}" comparision, but in the scale of things that impact is tiny.
My profession is not about finding and fixing bugs. It is about understanding the software that is being delivered and deployed. It is about understanding what defects exist (or may exist) and the possible implications of those defects. It is about reducing the risk of defects through analysis. Analysis of the software's functionality, analysis of the software's performance, analysis of the processes used to produce the software itself. You will never be yelled at for releasing software with a well understood and documented defect, but the shit will hit the fan when you release major defects that are not understood.
Logging is an _invaluable_ tool in this analysis. You'd be a fool to not use it effectively.
Re:not cpu bound... disk bound (Score:4, Insightful)
I tend to use log4j and asynchronous logging that passes log messages to a syslog server that can handle the file io - and it ends up being network overhead that is the killer.
People have said disk io, CPUs, and they say they are both cheap. NICs are VERY cheap.
Re:As little as practically possible (Score:4, Insightful)
There are more textures, and they are stored at a higher resolution than they used to be; The 3D models have more triangles; there are more sound effects, and the quality is higher; there is more music, and the quality is higher...It takes time to load all of this into memory.
Re:Reminds me of my uni days... (Score:1, Insightful)
Unit testing? You have to be kidding me. Next time your program fails in the wild because something happened you didn't think of, you'll go 'oh, unit testing isn't perfect after all.'
Unit testing only prooves your program passes the unit tests. It doesn't proove it does what's required to get the job done. Even you don't know that necessarially; perhaps there's been a change to the platform, perhaps you didn't Q.A. it for d/m/y dates. Perhaps you naively assumed that GMT+13 was an illogical timezone and never checked for it. These are things logs will help diagnose; unit testing will simply cause you to think the impossible is happened.
Re:As little as practically possible (Score:3, Insightful)
How can you demonstrate that you have fixed the reported bug if you can't recreate it in the first place?
Re:As little as practically possible (Score:2, Insightful)