Skip to main content

AOP is for tracing not logging

Every now and then I go and have a bit of search around for the recommended patterns and practices around incorporating logging in your application code.

It seems that this particular subject is one of those ones where someone said something a long time ago which has then been propagated to every nook and cranny of the internet until there is no room for argument or any contrarian views to be expressed. I am of course talking about the canonical answers given for .NET logging questions which are -

Just use log4net and Use Aspect Oriented Programming for logging

Well, I must offer a contrarian view on both of these points. I'll start with log4net and simply say that I agree wholeheartedly with this Stack Overflow post which effectively says that from .NET 2.0, TraceSource is built in and is a very effective mechanism to log whatever you need logged. It is also extremely extensible and you would really need some unique edge case to require something else. I have used the TraceSource classes in my own work and have written an event log listener that actually writes to the event log correctly (see my other post) and it works extremely well.

Now, onto the other bit of standard advice that is thrown out - use AOP for logging. Generally when this is suggested, the technique to implement logging is something like PostSharp which will modify the IL post compilation or perhaps the varying proxy interception techniques offered by most DI frameworks. However both these techniques suffer the problem of being too coarse for useful, context aware logging. These frameworks generally operate at the method entry and exit, as well as any exception that might bubble from said methods. Thus what these AOP techniques are most useful for is tracing and not logging.

But they're the same thing right? Not really. Tracing is concerned more about the execution flow of a program - it's almost like profiling. It's concerned with which methods were called, how many times and with what parameters. For collecting information like this, AOP is perfect.

However if you want to log some information you are usually looking at some kind of specific business event and the data you are logging will be well defined and well structured, which means you will likely want to add logging code at various levels within executing methods, instead of just around them.

How the logging code is injected is also typically a bone of contention, between the "just use a static" crowd and the "inject it" crowd. I have mulled over this dilemma at considerable lengths and I would say just use whatever suits your code base the best. While there is some more difficulty testing with a static member, it is not impossible and avoids property injection or constructor injection clutter. On the other hand, you may prefer the more granular control afforded by injecting said logging class. But in the end, it really doesn't matter just use whatever suits your codebase and your code style.

Oh and a final thought - if you are logging OR tracing using the .NET framework, or any Windows platform for that matter, please use Event Tracing for Windows and resist the urge to roll your own. ETW already handles the issues that come with building a logging system that you can think of and many that you won't think of until you have run your code in production for a few months. Have a look at this if you are doing Win32 dev or want a general example and my other blog post if you want a solid example in .NET

Comments

Popular posts from this blog

Writing to the event log in .NET - the right way

As a DevOper, I spend a lot of time instrumenting code. This involves adding stuff like performance counters, tracing and logging. One thing that constantly irks me when I go looking for ways or means to improve how I do my logging, is the complete and utter misinformation and misuse of the Windows Event Log. The problem relates to the canonical implementation of logging in .NET, log4net. Look at this method signature: void Info(object message); Note the lack of structure, the lack of context. Note the ability for a developer to put absolutely anything into the message object (which will be outputted as a string). When these types of messages are hooked up to an Event Log sink, the result is a generic message, usually in the Application log with a bit of free form text. Fairly useless for anyone to be able to filter and report on. The above style of logging is really more suited towards tracing and debug logging than actual operational logging, Why you should write operatio

SCCM 2012 - SMSPXE Error

I write this to help all you technical warriors out there who get shitty advice from the Microsoft Forums and other profound idiots about the 0x80092002 error in SCCM - usually to do with PXE booting but can manifest in other ways around DP -> MP communications. The tricky one about this error is that it happens even if you are only using HTTP communication and not HTTPS/TLS. So to get an error about certificates is somewhat confusing. What the uneducated masses of the internet will tell you is to re-install the PXE role over an over. This will do nothing. Then they will tell you to re-install your management point and effectively re-build your entire infrastructure. This will  work, but only because it is the nuclear option and will run the step that actually makes a difference as a matter of course. So, here it is folks. If you have these kinds of errors in your logs: PXE::MP_InitializeTransport failed; 0x80092002 SMSPXE 22/03/2017 2:45:58 PM 4144 (0x1030) PXE::MP_

Log Reader Error On Adding Subscription

Ever tried to add a new subscription to an existing publication, using the "replication support only" or "initialize from backup" methods and go the following error? The process could not execute 'sp_MSadd_replcmds' on <'Distribution Server>'. (Source: MSSQLServer, Error number: 1007) Conversion failed when converting the nvarchar value '.' to data type int. (Source: MSSQLServer, Error number: 1007) Batches were not committed to the Distributor. (Source: MSSQL_REPL, Error number: MSSQL_REPL22020) The last step did not log any message! (Source: MSSQL_REPL, Error number: MSSQL_REPL22037) If so, you will know the internet is absolutely useless, filled with worthless workarounds or advice to just "rebuild replication" Well, if you want an actual solution, just read on. Between SQL 2012 RTM and SQL 2012 SP4 there was a change made to the Distributor proc sp_MSadd_replcmds. This change was to facilitate a change in the format