RSS Feed

The Joel on Software Discussion Group (CLOSED)

I've got a few questions on logging/tracing in a medium sized system.
In the past I only logged errors and I've used either System.Diagnostics, or written to a error table in a db.
But as my system grows, I'm finding that it would be alot nicer if I could enable tracing on a user so I could
see what happens before and after the errors arise.

I've decided to go with NLog, since I've found it to be simple and fast...as well as the config files are pretty simple.

I'm curious to see how others implement logging,
Basically I would like to know how you determine what would be a Trace, Debug, or Info statement? Are there any rules that you use to determine this, or is it completely arbitrary?
Also would you put trace statements at the UI level, the component level, or both?

We have the following.

User front end - Logging
Loading System - Logging,Asserted
Core system    - Asserted

User front end typically deals with error checking, form validation all the boring stuff. So you throw requests back at the user to validate data, or update fields. Also telling them not to press that.

Saving and loading data, is a combination of logging and asserts. If an error occurs at this level its a design problem and no amount of logging is going to help the user.

Core system. Typically if anything happens here its a major design flaw and requires fixing. Nothing the user can do about it, we assert get a memory dump and fix the issue. As close to the error the problem occurred.

For .NET the $29 Kellerman Logger is great.
http://www.kellermansoftware.com/p-14-kellerman-logger.aspx

Josh in Jersey

The other thing we discovered, that may be of some help to you. Is to filter absolutely all user input via a single input area. So instead of having event handlers scatter all around the place, we had all the event handlers calling a single HUGE case statement similar to how window handles window messages.

The advantage of this technique, is you can record absolutely all the users input keys and mouse movements and replay them perfectly in real time for re-tracing a bug that has happened to the system.

This should allow you to re-wind, or fast-forward the users interaction with the application to duplicate the exact cause of the problem.

Most of the time, your not interested in the current state of the program but 2-3 actions before. Then you step through with the debugger, find the problem could of been interpolation or float overflow you had no idea about.

You say "System.Diagnostics" so I am going to assume you are running ASP.Net/IIS. 

In which case, for finding what a user did (like page paths), you already have some logging in IIS.  It won't give you debug type information, but it gives you a fair bit.  You just have to sort through it yourself.  (Querystrings help a lot as you can see them.)

Someone already asked exacty this question here: http://discuss.joelonsoftware.com/default.asp?dotnet.12.427471.5

Entity : Since all of the software I create is used in house, my main purpose for the logging is the ability to do what you mention in your second post,although not quite as detailed as mouse/key strokes...basically I want to be able to enable tracing on a user and have everything that the user does get logged...the only time the user knows about the logging is when there is a message >=WARN, which in that case they are presented with a dialog.


I forgot my name: Actually I just meant System.Diagnostics to write to the windows event log.  I mostly write Winforms but some of our apps are web based so looking at the IIS logs are a good idea.


Christopher : That post is almost what I was looking for.  The only thing is that Nlog has a TRACE element, which is below DEBUG.  As I mentioned above; I want to be able to turn on tracing and get a play-by-play of what the user is doing.  What are the recommended methods for enabling something like this.  Should I be putting TRACEs in every method in the UI and before calling a component methods, or should the components be responsible for doing their own logging.

What I was leaning toward was putting DEBUGs at the UI level that indicates what is being done at the lower levels, and using TRACE at the lower level.

The problem with that is when I enable logging of TRACE or greater I will end up with duplicates.

ie)
MainForm Saving file - DEBUG
Fileobj Saving file - TRACE
Fileobj Saved -TRACE
MainForm Saved -DEBUG

We recently switched to the microsoft application block for logging. (I would only suggest this if your application really needs it.) In our case we were already using WMI, event logs, log files, and storing audit trails in the database so it made sense consolodate the functionality. The application block made for a nice refactor.
http://msdn2.microsoft.com/en-us/library/aa480464.aspx

> TRACE and DEBUG

In ASP.NET I think that trace messages are always included in the build (and may be enabled via a configuration switch), whereas debug messages exist in debug builds (and may be enabled via a configuration switch) but don't exist at all in release builds.

Aside from that "debug" and "trace" are more-or-less synonymous. Some code bases have several levels of debug or trace, and the ability to enable different levels of verbosity in different modules.

> The problem with that is when I enable logging of TRACE or greater I will end up with duplicates.

I don't see that as a problem: for example if I were trying to debug a failure then I would want to know whether it failed in the UI or in the lower level, and so I want messages like that from each and every level.

In our enterprise asp.net app we use nlog very successfully. It is very fast, can write to logfiles (each day one file), supports highly customised layouts including the user identity as we use windows auth.
All critical errors are also written to windows event log, where the infrastructure team has automated monitoring tools to raise alarm if needed.

We use Log4Net

Trace levels:
Error - Critical Error
Warning - Recoverable Warning
Info - Method entry/exit
Debug - Method parameters, traces in the method body

Thanks  Christophe and Nullptr...thats the kind of information I was looking for.

Hello,

You might also want to take a look at our logging tool SmartInspect. SmartInspect supports so-called sessions in addition to traditional log levels. Sessions can be used to control the logging of specific application modules, classes or user sessions. SmartInspect additionally has a powerful viewer application for real-time monitoring, filtering and processing of log data:

http://www.gurock.com/products/smartinspect/

Greetings,
Dennis

Here's another perspective: Log Everything All the Time. More at http://highscalability.com/log-everything-all-time .