Logging to Database With Enterprise Library Part IV - Tieing it all together

In my last post we created all the plumbing that we needed to configure our logger. The final step is to create the actual logger. As a side note I want to say that tried to use TDD development for this piece; however, I have learned that TDD is not the greatest choice when your building plugins. I might elaborate on this in the future but anyways.

To create a custom trace listner for the Enterprise Library you need to derive from CustomTraceListener. You will then need to implement the TraceData function.

    [ConfigurationElementType(typeof(CustomTraceListenerData))]

    public class DBAuditLoggerTraceListener :

        Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.CustomTraceListener

    {

 

        public override void Write(string message)

        {

            throw new NotImplementedException("This method is not supported");

        }

 

        public override void WriteLine(string message)

        {

            throw new NotImplementedException("This method is not supported");

        }

 

        public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, object data)

        {

 

            AuditLogEntry ale = data as AuditLogEntry;

            if (ale == null)

            {

                //Not an audit log entry

                return;

            }

            IAuditLoggerExpressionGroup logGroup;

            if (!AuditLoggerExpressionCache.Instance.TryGetValue(ale.AuditCategory, out logGroup))

            {

                //Category not registered

                return;

            }

 

            using (StoredProcedure sp = new StoredProcedure(logGroup.Procedure))

            {

                foreach (string key in logGroup.Keys)

                {

                    sp.AddParameter(key, logGroup.GetValue(key, ale));

                }

 

                sp.Execute();

            }

 

 

        }

 

A couple of things to note, The Stored Procedure class is my own class which I am unable to share; however, all it does is wrap up all the ADO.Net Goodness. It also handles my connection strings which is why I am not passing the connection string in. You should be able to quickly whip up your own ADO.Net code. If you run into issues let me know and I will be glad to help out.

Basically all we are doing is making sure we have an AuditLogEntry object, then we check if we have created an ExpressionGroup for this AuditCategory. If we have we simply loop through each of the keys in the ExpressionGroup, calling the GetValue method.

GetValue was needed to ensure that this class didn't have to know about the type parameter in the Expression Group. I'm hopping C#4 with co/contra variance will remove this requirement. Finally we execute the stored procedure.

The next step is to configure this. If your using an ASP.Net app I'd recommend that you configure your expression Groups in the Global.asax. Also remember to call the Cache() method. If you forget this you will not save the expression group you have created.

The final step it to add your logger to the EntLib configuration for example:

<loggingConfiguration name="Logging Application Block" tracingEnabled="true" defaultCategory="Error" logWarningsWhenNoCategoriesMatch="true">

    <listeners>

        <add  listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.CustomTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging,  Version=3.1.0.0"

              traceOutputOptions="None" type="DBAuditLoggerTraceListener, YourAssembly" name="AuditLogger" initializeData="" formatter="Text Formatter"/>

    </listeners>

    <formatters>

        <add template="Timestamp: {timestamp}&#xA;"

            type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging"

            name="Text Formatter"/>

    </formatters>

    <categorySources>

        <add switchValue="All" name="Audit">               

            <listeners>

                <add name="AuditLogger"/>                   

            </listeners>

        </add>   

    </categorySources>

</loggingConfiguration>

I just noticed I had left the text formatter in there which I have not used. I am not sure if this is required or not.

So after all of this what do we have? A logger that will take any AuditLogEntry and execute a stored procedure, with any number of parameters. I hope you find this useful. Please feel free to provide any feedback positive or negative.

Enjoy!

Update

I have extracted the source and posted online. Please note that this is not tested, so if you run into any issues let me know. When I get caught back up with my day job I will try and finish rounding this out.

Let me know if this link doesn't work. First time I've used skydrive so I'm not positive I have it all setup right.

Logging to Database With Enterprise Library Part III - Expression Cache

In my previous post we started to explore a solution for logging any arbitrary data to the database using the Enterprise Library.

Next on our list of things we need to create our Expressions. Not wanting to create the expressions each time we need to log the data, and not wanting to tie our method for extracting data from the log entry to the log entry, I opted to create what I am calling the AuditLoggerExpressionCache or Expression Cache for short. The expression cache uses the singleton pattern to ensure we only have one cache for our process.

The cache doesn't actually store the expressions directly but it stores a group of expressions, keyed off the AuditCategory.

public class AuditLoggerExpressionCache

{

    private Dictionary<string, IAuditLoggerExpressionGroup> _expressionGroups =

        new Dictionary<string, IAuditLoggerExpressionGroup>();

    private AuditLoggerExpressionCache() { }

 

    public void Add(IAuditLoggerExpressionGroup group)

    {

        this._expressionGroups.Add(group.Name, group);

    }

 

    public IAuditLoggerExpressionGroup this[string key]

    {

        get

        {

            return this._expressionGroups[key];

        }

    }

    #region Singleton Pattern

    public static AuditLoggerExpressionCache Instance

    {

        get

        {

            return singleton.Instance;

        }

    }

    private class singleton

    {

        internal static readonly AuditLoggerExpressionCache Instance = new AuditLoggerExpressionCache();

    }

    #endregion

 

    public AuditLoggerExpressionGroup<T> CreateGroup<T>(string category, string connection, string procedure)

    {

        return new AuditLoggerExpressionGroup<T>(category, connection, procedure);

    }

 

    public bool TryGetValue(string category, out IAuditLoggerExpressionGroup logGroup)

    {

        return this._expressionGroups.TryGetValue(category, out logGroup);

    }

}

I have defined an IAuditLoggerExpressionGroup interface which allows us to access the groups without having to know the generic parameter type. I am using the Generics to improve the syntax since you won't have to cast the AuditLogEntry in your lambda.

public interface IAuditLoggerExpressionGroup

{

string Name { get; set; }

string Connection { get; set; }

string Procedure { get; set; }

Delegate this[string key] { get; }

IList<string> Keys { get; }

object GetValue(string key, object param);

}

A couple of key properties. The name here is the audit category, the Connection is intended to be used to store the connection string, the Procedure is the name of the stored procedure to execute. Keys is the keys to the expression dictionary itself. I am using the keys also as the stored procedure parameter names.

Let's look at the ExpressionGroup:

public class AuditLoggerExpressionGroup<T> : IAuditLoggerExpressionGroup

{

 

    private Dictionary<string, Func<T, object>> _expressions =

        new Dictionary<string, Func<T, object>>();

 

    public AuditLoggerExpressionGroup(string name, string connection, string procedure)

    {

        this.Name = name;

        this.Connection = connection;

        this.Procedure = procedure;

    }

 

    #region IAuditLoggerExpressionGroup Members

 

    public string Name { get; set; }

    public string Connection { get; set; }

    public string Procedure { get; set; }

 

    public Func<T, object> this[string key]

    {

        get

        {

            return this._expressions[key];

        }

        set

        {

            this._expressions[key] = value;

        }

    }

    public IList<string> Keys

    {

        get

        {

            return this._expressions.Keys.ToList();

        }

    }

 

    public AuditLoggerExpressionGroup<T> Add(string key, Func<T, object> expression)

    {

        this._expressions.Add(key, expression);

        return this;

    }

 

    public AuditLoggerExpressionGroup<T> Cache()

    {

        Check.Require(!string.IsNullOrEmpty(this.Name), "You cannot cache something without a name");

        AuditLoggerExpressionCache.Instance.Add(this);

        return this;

    }

    public AuditLoggerExpressionGroup<T> Cache(string name)

    {

        this.Name = name;

        return this.Cache();

    }

 

    public object GetValue(string key, object param)

    {

        return this[key]((T)param);

    }

    Delegate IAuditLoggerExpressionGroup.this[string key]

    {

        get

        {

            return this[key] as Delegate;

        }

    }

    #endregion

 

}

One thing to note I am using the Design By Contract class. This is however optional but if your not using it, be sure to go have a look its a great additional to your programming toolbox. The expression group as you see in the Add method takes a key, and a Func. T is your specific AuditLogEntry class, and we are returning an object.

At this point your unit test should work, and the vast majority of the work has been done. The only thing left is to define and configure the actual trace listener. I will cover this in Part IV of this series.

Logging to Database With Enterprise Library Part II

I've been surprised at how much traffic my little insight into the lack of functionality that the out of the box database log listener has in the Enterprise Library. So much that I figured it was time to share my first pass on creating a log listener that can dynamically pull attributes from a LogEntry and call any stored procedure.

To set expectations this is a first pass solution which took me a couple of hours to come up with. It is not complete by any means, and there is plenty of places that it could use work; however, it is 100% functional and solves the problem I was setting out to solve. I appreciate any and all feedback. If you take this code and improve upon it let me know I'd love to know!

I am currently using Enteprise Library 3.x, so this might have changed with their more recent 4.0 release.

When building this I had a critical to make which was how do we configure this? I wanted to be able to specify two values a parameter for the stored procedure, and a property / method to be invoked on the LogEvent object. I could have used reflection, LCG, code dom...there are lots and lots of options; however, I wanted to choose something that would be fast at runtime (Reflection is out), and that would be quick for me to code (LCG and Code DOM are out).

I opted for using Lambda Expression, which are very efficent at runtime, and which I could code to very very quickly. This is one area for improvement, right now the expressions can be defined in a configuration file; however, this is definetly something that is possible, and that I would love to add.

I built this so that defining the properties via configuration are optional. I've been using Fluent nHibernate lately and I've learned to enjoy the refactoring support that exists in defining your configuration in code. So the pieces that we need to implement are:

1. A dictionary of Expressions that call properties or methods on a LogEntry object
2. A trace listener that uses the dictionary to construct a stored procedure call
3. A log entry object that can tie the trace listener to the expressions

So let's get started. First thing I did was created a unit test to see what kind of interface I needed for my Expression dictionary. This looked like :

[TestMethod]

public void InitalizeExpressionCache()

{

    var cache = AuditLoggerExpressionCache.Instance;

    string category = "UnitTest";

    string connection = "[CutterMain]";

    string procedure = "sp_InsertUnitTest";

    cache.CreateGroup<AuditLogEntryUnitTest>(category, connection, procedure)

        .Add("MyProperty", ale => ale.MyProperty)

        .Cache();

 

    AuditLoggerExpressionGroup<AuditLogEntryUnitTest> grp = cache["UnitTest"] as AuditLoggerExpressionGroup<AuditLogEntryUnitTest>;

    AuditLogEntryUnitTest entity = new AuditLogEntryUnitTest();

    Assert.AreEqual(entity.MyProperty, grp["MyProperty"](entity));

}

AuditLogEntryUnitTest is a simple fake class to test the framework. I suppose you could substitute your own Mock using your favorite mocking framework:

public class AuditLogEntryUnitTest : AuditLogEntry

{

    public AuditLogEntryUnitTest()

        : base("Unit test", "UnitTest")

    {

    }

    public string MyProperty { get { return "MyProperty Called"; } }

}

Next we are going to define an AuditLogEntry class. This should be the base class for all of your auditing log entries. This class is defined as:

public class AuditLogEntry : LogEntry

{

    public AuditLogEntry(string auditMsg, string auditCategory)

    {

        //if (MembershipService

        this.Categories.Add("Audit");

        this.Categories.Add(auditCategory);

        this.Message = auditMsg;

        this.AuditCategory = auditCategory;

    }

 

    public string AuditCategory { get; set; }

}

This class adds an AuditCategory property, which is also added to the LogEntries categories so you can do filtering on it. The AuditCategory is important as it is is used to tie our LogEntries to the Expression Dictionary.

The next post in the series will explore the Expression Cache.

Logging to the database with Enterprise Library

Update:

I have since started my own implementation which is describered in the following articles:

• http://jberke.blogspot.com/2008/12/logging-to-database-with-enterprise.html
• http://jberke.blogspot.com/2008/12/logging-to-database-with-enterprise_12.html
• http://jberke.blogspot.com/2008/12/logging-to-database-with-enterprise_58.html

================================

So I've been using the Enterprise Library's logging block since v1; however, I've always logged to mostly unstructured or semi-structured locations such as email, files or the event log. I've had a lot of success using the block for logging exception messages or basic application events.

In all the apps I've ever written I've always had a need for a more robust strongly structured data store to facilitate reporting, and I've always resorted to rolling my own. Over the years the implementations have varried from very narrowly focused systems that support a single subsystem to more generic mechanism that support a various paradigm. For example logging of the messages within an SOA environment.

• Incoming Message
• Outgoing message to the next service
• Reponse from that service
• Response to the original request.

When ever its time to implement these systems, our team would always debate if we could leverage the Enterprise Library logging block; however, we've found that it was always easier to just roll our own quick dirty logger.

Today I had to ask this question again, only this time I am a team of one so I only had myself to argue with. I want to store an audit trail when a user logs into my web application, and collect all the fun stats such as his browser. (I know I could look at the iis logs but that won't let me profile which browsers have access to certain features, without having to figure out which urls if any compose a specific feature...this can be a whole other post so I will leave it at this).

The enterprise library does support a datbase trace listener out of the bat; however, it is seriously flawed. The listener can only log to a very specifc table structure. There is no way to say, I want to add this piece of information such as the IP Address of the client to the table as a seperate field.

The table does a text field called FormattedMessage which will use an Formatter that is asociated with the listener to generate a message. So while it is possible to get my IP Address in there, it forces to fall back onto to a non-relational model such as XML. While I love this flexibility, I've seen many DBA pulling their hair out at 3:00 am when they need to pull and aggregate data from a XML blob. Since this is a text field and not the Xml Data Type, I can't really enforce a schema.

So what is a poor developer to do? Well I don't have a solution implemented yet...But I plan on creating my own database trace listener that will let you specify the parameters and how to pull the values from the LogEntry object dynamically.

If I make any progress I'll add a new post. If anyone is aware of any solutions out there let me know.

Thanks,

Josh