Logging, do you do it?

Question

Back on my theme of late: interview questions. Was recently asked to describe a time I'd used logging.

My first instinct was to respond with compiler warnings set to full and error-out. What he was interested in was the use of logging as a debugging tool.

Unfortunately I couldn't think of one at the time except the one I was assigned because clients where having issues connecting to license servers and support wanted a log.

Thinking more clearly now though...I realized that I used to use logging a lot, and still do in little experimental projects. I still use it when developing on Unix systems, but not so much on Windows. Why? Because as much as I despise Visual Studio and think their compiler is maybe one of the worse around (I run into numerous bugs and issues with it every day), they got the debugger right! If I could put Visual Studio's debugger on gcc built executables I absolutely would. Add to this the use of unit testing to bring things into focus, I simply haven't needed logging very much.

On the other hand, maybe I'm really missing out. I have occasionally used it, and in fact some things that aren't exactly "logging" seem to me very similar. For instance, in debug mode the custom widget I created for this drawing application draws a bunch of extra visual clues representing bounding boxes and hot-spots. I also make very heavy use of assertions and exceptions.

I do have a bunch of mock classes that "log" but they're never used in the real program. For example, I have a custom drawing context wrapper that allows me to use the same drawing code for various UI API's. I have a version of it that simply spits out all the commands it receives to a string that I then compare to expected results. I use this to unit test drawing code.

If I where to use logging as a debugging tool I would want to do so in a consistent, standardized manner. On the other hand I'm at a bit of a loss to think of one. I suppose if I where writing something that surrounded network communication and such I would find it very necessary to have debugging logs and various verbosity outputs. On the other hand I write fairly simple UI programs by comparison.

So, do you use logging? What do you use it for? How does logging fit in your coding standards?

Answer 1

For any program/system of sufficient complexity, logging is absolutely vital. This becomes especially true when your device, application, etc., can be installed and used in odd environments or in conjunction with service providers over which you have little or no control (e.g. telecom, "cloud" providers,...).

In a complex system, it may be impossible to test or qualify every possible scenario for every release of your code. In one system our team was working on, we enumerated over 15,000 separate use cases. As clever as anyone thinks they may be ("I prefer not to write bugs"), you will never cover every possible case with perfect certainty that nothing else was affected by seemingly minor changes.

Logging provides the means to detect error conditions, and more importantly, what lead to the error condition being exercised.

On release, log levels should be set high so that only the most important messages get logged, but that threshold should be easily configurable so that a customer exhibiting problems can lower that value and provide more details to those supporting the product. Likewise, it is important that your system is responsible for cleaning up its own mess -- make sure you either use the underlying system's log system (syslog or SNMP) or write your own so that your log files don't overwhelm the host by filling up disks and so on.

I would prefer not to write bugs as well, but we're all human, and the more people you add to a project the more complex it becomes. If you're building something which may eventually become large and/or complex, get a decent logging system in early. You'll be thankful for it later.

Answer 2

I work in an environment where we cannot expect errors to be reproducible or be able to attach a debugger to the program.

This has lead to a very defensive programming style, where we basically log a lot of things on the lowest level, which is then enabled when problems are expected or we are in a test phase. The next higher log level is a lot less verbose and is enough to see that processing is taking place, and what is being processed. This is the level for stable production.

For Java you also need to make your stack traces as telling as possible since this is a single unit which can contain a lot of information. By suitable catching and wrapping in a new exception with information about the execution environment you can see parameters, full file names, iterator values etc. but only see it when something goes wrong. This is perhaps the most powerful post-mortem mechanism available today.

Answer 3

So first I work in large scale embedded systems not small ones that have no memory or tools, although I have worked on those as well. Basically I work on something that resembles a server but is not. Here are the uses and reasons for using logs:

• With many many systems in the field rarely, if ever, can you attach a debugger so a history of how you got where you are is invaluable.
• Not often can you have a debugger on all of your systems in test so again history is important.
• Some things a debugger can't really capture like how the system runs over time. Are there things that happen that are not bugs but you need to be aware of and potentially do something about.
• If I took away your debugger today how would you solve a problem? I think debuggers are great but not always the best tool for the problem. It helps to have more than 1 tool in the toolbox.
• Collecting use patterns.
• Working on multiple systems that are constantly interacting with one another. A debugger makes this very hard where logging, providing you have a common time source, makes it very easy to tie these things together.
• Working on something that is real time and you cannot halt the CPU because that would cause everything else around it to alter their behavior.

Answer 4

I've used logging as a method of low level audit tracking for a webservice. Each request that came in I logged to a file with some small logging of what action was taken etc. The log files were periodically purged by scheduled jobs. I found this handy to identify issues with other peoples data that was sent and initially helped iron out any issues/cases I hadn't written.

If I was going to suggest any standards around the logging I would probably suggest just being consistant with your output columns and standard information as this may help for bulk parsing or searching etc if required further down the track.

Answer 5

I like logging, log4net rules, here are various thing things I've used it for.

• To trace through multi-threaded code and identify timing errors
• To demonstrate to customers that functionality is complete at the end of a sprint even when there is no UI
• To selectively verify the functionality of different components
• Redirecting the log output to something like Growl so that I can see internal messages in real time.
• To force myself to think in terms of what a business person might want to see in a log (not a lot of point in logging "enter method, exit method messages", a trace tool and a IL rewriter can do that.
• To generate an audit log (though I'd prefer something like event sourcing for that)

Answer 6

I use logging fairly often, especially for applications that are heavily dependent upon unmanaged resources that I have less control over (network I/O for example), and for applications that are difficult to debug properly from within Visual Studio. There are also things that you might want to log in the production environment that you can't log just through debugging, such as user activity, unexpected occurances / exceptions, etc.

For example, at work I recently wrote an application for data transfer. I had to figure out a way to transfer data from an external server that I control to a server within a government network that I control. Large amounts of data have to be transferred daily. I exposed the external data by developing some web services for the external server. Then I wrote an application that is scheduled to run periodically on the internal server. The internal server passes authentication information and requests for specific data to the external server via SOAP headers. The external server then returns the serialized data over HTTPS via XML. Because there is a large amount of data involved here, the fact that we have a contractual requirement to keep the data up to date and available on the government network, and because of the fact that I am relying on ISP networks which I have little to no control over, I need to be able to log what goes on with the data transfers so that I can troubleshoot issues. The data transfer software keeps its own logs and also logs events to the event viewer for the server. Then I expose this data via an intranet website so that I can quickly check the status and health of the data transfer system and the internal database.

I also use logging for security purposes in my production applications. Some of my web apps log user activity for example, and most of my web apps will log any exceptions that they encounter into a SQL Server database so that I can catch and fix bugs quickly.

Another scenario where I recently used logging was when I needed to quickly install some event handling routines on our SharePoint server. I didn't have time to set up a proper virtualized environment for sharepoint or a test server either. I added the SharePoint.dll to a project and wrote the code, read through it meticulously and made sure it compiled, but I didn't have the proper environment to actually run the code and attach it to a debugger. So as I was developing the application I would periodically install the assemblies to GAC on the server and register them with sharepoint using an in-house utility that I wrote. I had the event handlers write a lot of informatino to the event viewer on the server so that I could see that they registered with SharePoint and were working properly.

I think I worked on some InfoPath projects before where a couple of them could not be attached to a debuger for whatever reason as well. I think in that case I simply wrapped DEBUG pre-processor directives around certain parts of the code while I was debugging and troubleshooting so that it would pop-up messageboxes to let me know what was going on. I'm sure we've all done that before. That is basically how I debug javascript as well (with alert boxes that I comment out later, lol).

As far as common practices go....one thing that I always do in all of my .NET classes is override ToString(). My ToString() override generally returns all important state data for my type (properties and member fields, etc.). This is useful for a lot of reasons, and logging is certainly one of them. If you are trying to hunt down an issue or keep track of things in the production environment you can leverage ToString() a lot in order to log a printout of a types state at any given time.

You can use the EventLog class in System.Diagnostics if you are a .NET developer to write straight to the Event log of the system if your code has the appropriate permissions. You can also use System.Diagnostics.Debug and System.Diagnostics.Trace for logging purposes. Trace is useful because you can write directly to the output window in Visual Studio which goes hand-in-hand with debugging. You can also create your own Performance Counters for your application for use with the Performance Monitor mmc snap-in in Windows. In reference to your question, you can see that Microsoft considers logging to be a common requirement for a given peice of software, in fact, many if not most of their applications employ some type of logging.

So to answer your question, yes, logging can be very useful, and is in fact very common.

Answer 7

As a debugging tool - never. I prefer not to write bugs in the first place. But if you are writing a multi-threaded transactional stock exchange server (or something similar), where OTHER PEOPLES activities may cause problems , then a log is handy in the blame game.

So, log external inputs, transactions, and your outputs, but nothing below that level, otherwise the logs become incomprehensible and slow things down too much.

Answer 8

I've used logging a few times. I had a bug once that could only be reproduced on a user's machine with their data. No way to attach a debugger and see what's going on, so I put in some logging statements around where I thought the problem was taking place, sent the build to them, got the results back, put in more logging where the log indicated the bug was happening to narrow it down further, and so on. After 4 or 5 iterations of this the the nature of the bug became obvious and I was able to fix it.

Answer 9

I write code per my functional requirements. If the requirements include logging then I write logging. If they do not then I do not include undocumented features. If I am doing something that does not require logging and I really feel that it should then I talk with the PM. There may be business reasons to or not to log.

Answer 10

Yes, I find it very useful for several kinds of things:

• Working with very large data files. When you're looking to see what's being misinterpreted in a 30 GB input to cause some state to change and the program to go south, hitting the same breakpoint a million times isn't an option.
• Working with networking code. If you sit for a couple of minutes staring at a debugger and puzzling over what's going on, the connection will drop.
• Dealing with complex code somebody else wrote. Many times, a client will want a bug fix yesterday, and there's not really time to become an expert or do anything more than a band-aid. In skanky code, any number of dumb things could lead to a given bug; logging the heck out of things will often tell you which dumb thing is leading to your particular bug.
• Turning intermediate binary data into something more human-readable than a debugger will do.
• Working on embedded systems, where you compile on a desktop and transfer binaries to the target hardware, and the target hardware doesn't have a debugger.

Answer 11

As a tester, I use logging extensively as a debugging tool. Debuggers are great when the bugs you encounter are reproducible, but don't do you any good if the error is only hit once and can't be repeated the next day (due to unknown parameters). In that case, you need more information about what, precisely, was happening in the environment so you can have a better chance of reproducing that issue. Ability to log probably ranks right up there with ability to mock for testability, depending on your application.

Coding standards: Have multiple levels of logging: Normal levels are an 'error' level, a 'Standard' level, and a 'Debug' or 'Trace' level. Log all exceptions in "Error", including stack traces; major program state changes (e.g., restarting a service) in "Standard"; and relatively tiny details in "Debug" mode. Have Error and Standard on by default unless there is a reason to turn them off.

Debug mode should generally be turned off except for testing or when gathering information on a potential issue, but should have enough information to give a pretty good picture of the program status; log to this liberally with file identifiers, data, and updates on what the program is doing. Some people will actually log every function being called. Note that extreme logging can affect performance, so you may want to turn off your debug logging when performance testing.

Move log files into an archive folder and start a new log file automatically every so often, so that the files don't get too long to be usable.

Answer 12

I'm quite amazed to hear that everyone doesn't use logging for debugging. If you don't use logging for debugging then answer the question, "How do you figure out what went wrong when the user tells you I was performing activity X and then the system crashed but they don't really know what they did and of course you can't duplicate the problem" OR "When bugs are intermittent and may or may not happen for weeks or months".

I guess if you don't owe your customer quality then it would be ok to just blow their problem off, but when your contract requires you to fix problems then I don't see any other way to give timely fixes for obscure problems other than using log files.

Answer 13

The main reason I've used logging is where I simply can't trust users to give accurate details of what they were doing when the "error" occurred.

If I have logs then I pretty much just need who they were and when it was and I can go and see what they were actually doing, not what they think they were doing.

As our product is used by largely non-technical users this is essentially all the time.

Defining what to log is hard though and is largely an evolutionary process. You make a reasonable first stab and then it gets enhanced as particular code / areas are found to be problematic. Taking your lead from your system test results can help as they're obviously indicative of actual problems which have been seen - yes they may have been fixed in my experience issues clump around certain functions and code (usually as a result of complexity) so if you've seen an issue in one area I'd suggest that you're more likely to further issues there than at some random location.

One thing I would always log - all input and output for any integration with third party systems. First thing the other vendor asks for when you raise a problem.