Obiwan Jacobi

Deploy Role with caching enabled to Windows Azure

Marc Jacobi — Mon, 18 Feb 2013 14:06:00 GMT

I am currently setting up my first Azure project. I had a skeleton Solution with a Web Role (MVC 4) and a Worker Role.

To test the whole cycle I wanted to deploy early. We are using the visualstudio.com TFS, which can be coupled to Azure (or actually it’s the other way around) and a continuous deployment build template is available there (AzureContinuesDeployment.11.xaml).

I was experiencing unhealthy instances and timeouts (when the build script took more than one hour to execute – due to the deployment steps) after deployment. After some searching and experimenting I came to the following conclusion.

When you select the Caching option in the Role Properties, you MUST enter a valid Storage Account for deployment on Azure.

By default the configuration for that setting contains the well-known “UseDevelopmentStorage=true” value. While this is fine for running locally it absolutely will not work when deployed on Azure.

The Storage Account Name and Key can be found on the Azure Portal – Storage tab. Select a Storage account there from the list. Then in the App Bar (below) there is an option Manage Keys. There you can copy the relevant values. Note that I used the primary key. Not sure if it works if you use the Secondary key.

In hindsight it is logical and obvious, but it took me a good while to figure out that THAT was the problem.

Hope it helps.

Yet Another Logging Framework

Marc Jacobi — Fri, 21 Oct 2011 11:30:27 GMT

This blogpost is a brain dump on a new logging framework I’m planning to write. If you have any additions or suggestions please leave them as comments.

So why do we need, yet another Logging Framework. Well, because I cannot find in others what I think is important and also I want to leverage the Diagnostics Trace code I have already written.

What scenarios should this Logging Framework be able to handle?

Easy to use.
It should be easy to configure and easy to call. Any provider based mechanism (log targets) is bound to have config associated with it, but at least give good feedback on any problems that might occur. Convention over configuration and MEF might ease the problems.
One liner.
When using it, you should only have to write one line of code. This is not always feasible but it is a good starting point. Why is this important? Because you want to make it easy on the poor developer that is using your ‘yet another logging framework’. The use of Aspects (PostSharp) can also be of use.
On the other hand, most applications that use a 3rd party library almost always create a façade for interacting with it. So its better to have a good API that is easy to integrate into a façade than to have an awkward API in order to force it all into one line of code.
Uses the TraceContext (source) information to ‘automatically’ enrich the log entries. The TraceContext now has a method to AddContectTo an Exception, but could be extended to also AddContextTo a LogEntry.
Fallback log targets.
Have a mechanism to fallback on log targets when they are not available. This answers the question: were do you log the exception that you cannot connect to your log target.
Integrated .NET support for WCF and ASP.NET.
Make use of the extra information that lives in those contexts and allow that context to be easily added to the log entry. Both these contexts also support some kind of interception (think Behaviors for WCF and Modules for ASP.NET) to allow automatic logging.
Log to multiple log targets at the same time – each with unique filters.
The default System.Diagnostics TraceListeners will already do this. Also be able to retrieve different types of logs in the code (error log, message log, security audit log etc).
Use that same log framework for technical logging as well as functional auditing.
There is no reason why a logging framework cannot be used for (more) functional logging also, provided the they use unique ‘streams’.
Different log entry formats.
Different log targets may require different log entry structs. Still I would prefer to use the existing diagnostics code. This means that those structures has to be serialized and deserialized. I think JSON can be of great help here.
Distributed and Correlated.
You want to be able to correlate log (and trace) entries made by different parts of the system. This allows you to get a good impression to what happened where and why.
Support debug-only log entries.
Conditional compilation on DEBUG. No biggie, just useful.
Asynchronous logging.
This is tough one. You want Async logging in order to minimize performance impact on the running thread – actually this is more a tracing issue than a logging issue, assuming logging doesn’t output a whole lot of entries per second). But making it asynchronous can also mean that you lose that one vital entry just before the app crashes. More on this later.

Using System.Diagnostics

The idea is that we use as much of the existing logging technology as possible. That means reusing and extending the main classes of the System.Diagnostics namespace. TraceSource can be derived into LogSource and provide the basis for a log target. Each LogSource can specify a collection of TraceListeners. Custom TraceListeners can be used as well as the out of the box ones.

But using these TraceListseners means that all Log information has to be squeezed through a single string (essentially – worst case). This coupled with the fact that different log types might require different log entry structures leads to one conclusion. We have to serialize the complex data into a string so that it can be output by different log targets (Sinks) and mapped to their most appropriate fields.

The use of JSON would be excellent here, also because JSON is somewhat readable even in its serialized form. So you can still make sense of it even when its written to a text file. The object structure that is used will be partly fixed, we will need some known fields to extract data needed for further processing. But custom structures can also be easily serialized to JSON and on the receiving side, easily serialized into generic data containers (ExpandoObjects) for use in the viewer.

Formatting this complex data into something that makes sense for the specific log target is done when reading the log, not while writing it. This not only saves a little performance hit while writing the log entry, it also allows for a more versatile viewer.

Performance

One of the obvious ways to decouple the performance costs of tracing and logging is to take the processing of the log entry onto a background thread. Only the data gathering takes place on the active thread all other operations will be done on the background thread.

The trouble with this is that you can lose potentially critical log entries just before your application crashes. One possibly way to have the best of both worlds is to use the log level (Critical, Error, Warning and Info) as an indication of priority. That could mean that Critical log entries are always logged on the active thread. The other levels are processed by the background thread starting with Error, Warning and Info as least significant.

We have to provide some way to identify the order of these entries (can be a simple sequence number) in order to be able to view them in the correct order. Gaps in the sequence can be detected and displayed in the viewer. This mechanism will also make it easy to merge log ‘files’ from different machine into one.

If we take formatting out of the write-a-log-entry process, we might also need to revisit the Tracing code we have so far in order to make that option available in Tracing too.

Reading Log entries

For each (type of) log target a Sink is needed that knows how to put the log entry data into its storage. Think for instance Enterprise Library Logging block or Log4Net or simply the event log. A TraceListener is implemented for each target that knows how to take that one string and persist it in the most optimal way.

When those (types of) targets also want to play in the log viewer, they also have to expose a Provider: an object that knows how to read log entries from its storage and provide them to the viewer.

The viewer will be able to union all log entries from all providers and sort them into the temporal sequence they were written in. Merging of different (machine) sources is also possible.

Of course the viewer would be able to filter and even search through the entries.

I think it would be advantageous to implement an OData REST service as a source for all the log entries. This allows easy access to the log entries for all kinds of purposes and provide a flexible basis for retrieving log entry information for different applications. Both Xml and Json formatting can be supported.

Closing remarks

I am sure that a lot more issues will present themselves once a more detailed design is made and implementation starts. But I think this WILL make a pretty nice logging framework if we can pull it off. Writing this blog post has helped me to structure my thoughts more on the subject and I hope it was a pleasant read for you, perhaps even an inspiration to tweak the logging framework you are no using.

Seesmic Desktop Feed Reader Plugin

Marc Jacobi — Mon, 24 Jan 2011 10:30:00 GMT

Hi,

I've released a Seesmic Desktop plugin that allows you to read syndication feeds (Rss/Atom) in a single column.

It has been published on the Seesmic Marketplace and is also open source.

Give it a spin and let me know what you think.

Have fun,
Marc

The context of anonymous methods/lambda's is lost on async proxy calls in SL3 (Updated)

Marc Jacobi — Thu, 10 Jun 2010 10:25:00 GMT

EDIT: This issue was caused by using cached singletons for each proxy (see comments). So the context of anonymous method works correctly, it just appeared it didn't because multiple event handler (lambda's) were registered to the same proxy instance.

We're building an SL3 application that gets its data from a WCF (Ria) Service. The application uses a standard generated proxy (SlSvcUtil.exe) and all calls are done using the familiar async pattern: call a begin method and wait for the completed event. In our SL3 application we have some layers on top of this Proxy:

1) The ServiceAgent - manages the service proxy and transparently recreates it when it is in a Faulted state. It subscribes to the completed event on the proxy and promotes this to the caller (repositories).
2) The Repositories - exposes centralized and cached data access divided bij functional area / domain.
3) The Model (per module) - Each module in the app implements the MVVM pattern and its model accesses the repositories and maps the data from service contracts to module-specific view entities.

Because all data fetching is async we use an eventing mechanism (similar to INotifyPropertyChanged and INotifyCollectionChanged) to communicate'the 'completed' event from the proxy upward through the application.

It was in the implementation of the repositories that I first discovered that something was wrong with the context in which our 'completed' events were raised. Our implementation looked something like this (pseudo code):

public DataEntity GetDataEntity(Guid Id)
{
    DataEntity retVal = new DataEntity();

    using(var proxy = _serviceAgent.GetProxy<RequestDataContract, ResponseDataContract>())
    {
        proxy.RegisterCompletedHandler( (response) =>
            {
                retVal.Property1 = Response.Property1;
                retVal.Property2 = Response.Property2;
                retVal.Property3 = Response.Property3;
            });
        proxy.BeginRequest(new Request(id));
    }
    return retVal;
}

Initially this method returns an empty object that gets mapped to an empty ViewEntity and bound to the UI. When the proxy reports the service call is completed the 'CompletedHandler' is called implemented by the lambda and provides access to the response of the service call. Now the empty DataEntity is filled and these changes are propegated to the ViewEntity (think INotifyPropertyChanged) and in turn the Viewentity notifies its changes to the UI (also INotifyPropertyChanged). This works, no problem.

Untill you place another call to the same repository method while the first is still 'running'. Then the 'context' the lambda needs to fill the retVal is lost and 'overwritten' by the second call. So it may be very well that the result of the first call is written to the retVal of the second call. You can imagine the strange behavior you'll get in your app (and how long it takes to figure out what the problem is ;-).

The solution that I've found is to use the userState that the proxy allows you to sent with a method call. The pseudo code will look something like this:

public DataEntity GetDataEntity(Guid Id)
{
    DataEntity retVal = new DataEntity();

    using(var proxy = _serviceAgent.GetProxy<RequestDataContract, ResponseDataContract>())
    {
        proxy.RegisterCompletedHandler( (response, userState) =>
            {
                DataEntity de = (DataEntity)userState;
                de.Property1 = Response.Property1;
                de.Property2 = Response.Property2;
                de.Property3 = Response.Property3;
            });
        proxy.BeginRequest(new Request(id), retVal);
    }
    return retVal;
}

Now the correct retVal is passed as userState allong with the service call to the proxy and the completed (event) handler will now have access to it when it is called and will be able to set the property values.

I was very suprised that this occurred in my code and it may very well be that I'm doing things wrong, but I don't see it. Any suggestions are welcome.

Hope it helps.

Services with a twist

Marc Jacobi — Fri, 21 May 2010 06:52:00 GMT

On the project I am currently working on we have several layers of processing going on:

External Systems (silos)
These are the legacy systems that contain all the information.
A service layer (WCF)
These Domain Services expose the legacy systems transparently. Talking to these services gives you no clue which legacy system is used. Sometimes its more than one.
An Enterprise Service Bus (BTS2006R2/ESB)
Positioned as messaging middle ware. For the most part completely transparent to the clients.
Client / Front end applications (SL3)
User applications that consume domain services through the ESB.

In order to let our domain services perform optimal with the many calls that they'll receive and to make them as versatile as possible, we've decided to do two additional things:

Support Batching
Most service methods can handle multiple requests at a time. Its like taking your normal service operation contract and putting a collection around it. This enables the client to (for instance) resolve multiple IDs in one single call / round trip. It is the classical choice between multiple calls with small messages or less calls with larger messages. The client can now choose how it wants to interact with the service.
Support Prefetching
We define a rich data model that each of these domain services work with. These services go beyond just 'Customers' or just 'Orders'. Because all data within a domain service is so related / connected we felt that it would be best to keep it all in one service. But you do not always want all 'Orders' and all 'OrderItems' and all 'Product' for a 'Customer'. So we allow most service operations to specify what we have called 'Prefetch paths'. Basically you call the service operation and you specify what relations of the root entity that operations serves up you want also to be included in the response. So you could call GetOrders with only the 'OrderItems' prefetch key. That would result in all Orders and OrderItems for a Customer. The client once again is in control of what data is retrieved to suit its needs.

We understand that implementing services this way is somewhat non-standard (I have never seen it done before), but we feel that it provides a lot of flexibility to its clients. For a service to be reusable in a number of different contexts, we believe it should be more flexible that your normal, plain vanilla service. Nontheless, we really like some community feedback on this design and would appreciate any suggestions you might have.

Silverlight: Breaking the daisy chain?

Marc Jacobi — Wed, 14 Oct 2009 05:59:00 GMT

This post discusses the consequences of calling asynchronous calls in Silverlight (or any other scenario that lets you pass in event handlers for completion notification).

Everything is asynchronous in Silverlight. With each call you make, you pass down event handlers that are called when the operation is done. When trying to program a sequential execution flow in your Silverlight program, you'll see the daisy-chain 'pattern' emerge. This is where a method starts an asynchronous call, the event handler does some work and starts another asynchronous call then the next event handler performs another asynchronous call, etc. Look at your own Silverlight code and see if you can detect this pattern.

You see your logic spread out over a couple of methods/event handlers. Question is: does this need fixing? From a puristic standpoint I would say yes. On the other hand I can see that a daisy chain might not be the worst you have to live with. When the logic is simple enough and following the chain is easy, it is all right to leave it at that. But what if at some point you have to branch of the chain? For instance you have a condition (if-then-else) that determines to call one asynchronous method or -if it is not true- it will call another asynchronous method. Now you have two parallel tracks the execution flow can follow down the chain. This can get messy very quickly.

Another issue to remember is that the thread that is used to call your event handler and notify you of the outcome of the asynchronous call, is not necessarily the same thread that was used to create the UI. So you cannot call into the UI directly from within the event handler. You have to marshal the call using Invoke.

But how do we solve this? One pattern comes to mind is the state table. Define a state for each step in the daisy chain and determine what state to go to next when an event handler is called. But this doesn't do anything for the fragmentation of the code. Its just a different way of cutting it into pieces and I would argue its less obvious than the original daisy chain (its also not entirely what the state table was meant for).

You could use anonymous methods (or lambda's) to pull everything into one method, but the question is if this is more readable and maintainable than a daisy chain.

Although I have not worked out the details of this idea, I was thinking of a base class that would implement some helper methods to perform asynchronous calls and provide event handlers. This should allow you to implement all your code in one method (or as many as like) and call asynchronous methods and gather their responses almost transparently. Not sure if this idea will work, though.

What I would like is to code out my Silverlight code in a normal sequential flow using "normal" programming paradigms and patterns. But until someone comes up with a good solution for that, we just have to experiment with our own solutions and patterns.

[Link] .NET Code Pack for Windows 7

Marc Jacobi — Thu, 10 Sep 2009 07:56:00 GMT

This seems to be .NET wrapper classes and controls for the new Windows 7 features.

http://code.msdn.microsoft.com/WindowsAPICodePack

sweeeet....

How to implement catch (Exception e)?

Marc Jacobi — Fri, 10 Apr 2009 15:40:58 GMT

How often did you see a C# catch(Exception e) statement in code? How often did you write it yourself?

I know I do it, even when I know I shouldn’t. Why?

Because its so easy! Doing it right is hard(er) or at least take much more code you have to repeat over and over again.

But its not something that you’d be proud of (I’m not).

So, I thought it was time to change that. But how? I definitely don’t want to rewrite a lot of code for each try-catch-finally block.

First lets take a look at error handling. When do you really handle an error? Almost never I dare to say. I’ve only encountered one occasion where I really handled an exception (a dead-lock exception from SQL-Server: I waited a random amount of time a retried – three times. After that I just let the exception bubble up).

What does your error handling code look like? I bet it looks something like this:

    try
    {
        // real code here…
    }
    catch(Exception e)
    {
        Logger.LogException(e);
    }

I don’t see the handling part in this ;-) why do we call this error handling? BTW don’t call throw e in the catch block. I rewrites the call stack and you loose the original call stack.

But there’s a whole range of exceptions you don’t want to catch. AccessViolationException? ExecutionEngineException?

Those indicate situations you can’t fix anyway.

How about InvalidCastException and NullReferenceException?

Those exceptions indicate some technical error and are an indication of plain bugs. I wouldn’t want to catch those in my code (only at AppDomain level to log them).

The good news is that the BCL team is doing something about this in .NET 4.0. But even in .NET 4.0 catch(Exception e) is still not a good idea.

But how do we handle exceptions the easy way (the catch(Exception) way) but filter on the really important exceptions? We can take the solution of the BCL team one step further.

The following code is not production code but it demonstrates an idea to handle exceptions correctly once and for all.

    public class ErrorHandler
    {
        public delegate void TryCallback();
        public delegate void ExceptionCallback(Exception e);
        public delegate void FinallyCallback(bool? exception);

        public ErrorHandler()
        {
            // add "really" fatal exceptions by default.
            FatalExceptions.Add(typeof(AccessViolationException));
            FatalExceptions.Add(typeof(ExecutionEngineException));
        }

        private List<Type> _fatalExceptions = new List<Type>();
        public IList<Type> FatalExceptions
        {
            get { return _fatalExceptions; }
        }

        public bool IsFatalException(Type exceptionType)
        {
            if (!typeof(Exception).IsAssignableFrom(exceptionType))
            {
                throw new ArgumentException("Specified type is not (derived from) System.Exception.", "exceptionType");
            }

return (_fatalExceptions.FindIndex(e => e.GetType() == exceptionType) != -1);
}

        public bool? TryCatchFinally(TryCallback @try, ExceptionCallback @catch, FinallyCallback @finally)
        {
            bool? handleException = null;

            if (@try == null)
            {
                throw new ArgumentNullException("@try");
            }

            try
            {
                @try();
            }
            catch (Exception e)
            {
                handleException = HandleException(ref e);

                if (@catch != null && !IsFatalException(e.GetType()))
                {
                    @catch(e);
                }

                if (handleException != null)
                {
                    if (handleException == true)
                    {
                        throw e;
                    }
                    else
                    {
                        throw;
                    }
                }
            }
            finally
            {
                if (@finally != null)
                {
                    @finally(handleException);
                }
            }

return handleException;
}

        public bool? HandleException(ref Exception e)
        {
            bool? result = null;

            if (e != null)
            {
                if (IsFatalException(e.GetType()))
                {
                    // throw
                    result = false;
                }
                else
                {
                    // TODO: call EntLib exception policy

                    result = false; // for now
                }
            }

            return result;
        }
    }

The HandleException method is where it gets decided whether an exception is handled and how. This is also the place to integrate EntLib if you desire. The return value of the HandleException can be null (do nothing), false (call throw) or true – meaning the exception has been replaced (exception wrapping) and throw e should be called. You could elaborate the catch callback to include retries of the @try code when you actually handle an exception (like the dead lock example earlier).

You could use this code as follows:

    public void MethodThatCouldGoWrong(string someParameter)
    {
        ErrorHandler errorHandler = new ErrorHandler();
        errorHandler.FatalExceptions.Add(typeof(InvalidCastException));
        errorHandler.FatalExceptions.Add(typeof(NullReferenceException));

        errorHandler.TryCatchFinally(
            delegate() // try
            {
                // do something here that causes an exception
            },
            delegate(Exception e) // catch
            {
                // handle the exception e
            },
            null    // finally
            );
    }

This code will not call the catch callback on AccessViolationException, ExecutionEngineException, InvalidCastException and NullReferenceException.

You probably don’t want to instantiate the ErrorHandler class each time you need it - you could make it static as long as you add all fatal exception during initialization of that static instance. Then its a matter of calling the TryCatchFinally method and doing your processing using anonymous delegates (I think in this case its more readable than lambdas). You can even pass null to the @catch callback if you don’t have any custom handling to perform but still get your exceptions ‘handled’.

So its a start. Maybe not perfect.

Thoughts?

[BAM] PivotTable names must be unique

Marc Jacobi — Tue, 05 Aug 2008 10:05:00 GMT

More a note to self than a serious blog post (haven't got the time to do screen shots and stuff).

When creating BAM views in Excel, you can copy the initial PivotTable that is generated to create multiple predefined 'views'. To copy the PivotTable select it (go to the edge until you get a solid arrow cursor) then Copy it (Ctrl+C), select a free cell well below the existing PivotTable and Paste (Ctrl+V). Right-click in the Pivot Table and select Table Options... to give it a name. This Name must be unique across the workbook. Otherwise the PivotTable will not be linked to a cube when exported (although it all seems to work in excel) and your view will be missing from the Aggregations node in the BAM Portal navigation pane.

[WPF] Data Model - View Model - View

Marc Jacobi — Sun, 29 Jun 2008 12:14:48 GMT

This post is based on an interpretation of a pattern called View-View Model-Document or View-View Model-(Data) Model. I did not invent it. I just write this to have a record of what I learned when exploring the design pattern.

The following figure displays the WPF Application Architecture. On the right side a legend explains the meaning of the shapes used in the diagram. The Xaml shape indicates artifacts that are typically created with Xaml. The WPF shape indicates to a WPF specific type and the class shape indicates a custom class specific to the application in question.

The dashed lines show a Data Binding dependency with the arrow pointing toward the dependency being bound. The solid line with the arrow also displays a dependency but one that is set on the named property. A solid line with a diamond represents containment (diamond being the container). Multiplicity of this containment is indicated with the numbers at the “containee”.

View Rendering

The View Model is set as Content on the View. The ViewModel will provide object instances that drive the View’s content. These instances are usually Data Model types but can also be other view specific types. Through the use of Data Templates the ViewModel type and the Data Model type as well as any other types the View Model might provide are “converted into UI elements”. Each Data Template is written specifically for the object type and has knowledge of the object hierarchy within one instance.

There are two options in how to interpret the Data Model. Some would consider the Data Model to be the collection of all application data (not necessarily counting view or UI specific data). Others would design a Data Model class to manage only one instance of one entity. A Data Model that is modeled to manage one or more collections of data can be harder than to bind against than a Data Model that manages only one entity instance. Either way can work with this architecture although it must be said that creating a Data Model that only passes through the information of the entity must be avoided.

With the View Model and the Data Model in place the View can be data bound and the content is rendered in the View based on the View Model Data Template and the Data Model Data Template.

Note: A major drawback of working with Data Templates is the lack of support for Visual Designer Tools (Blend and Visual Studio). These tools will help you design views but not as a Data Template.

Command Handling

Just rendering a view is like a glass window: you can see everything but you can’t do anything with it. A user interacts with application by clicking and typing: generating events. This architecture proposes to use Commands to route these events to the application (code). WPF predefines several categories of commands that can (and should) be (re)used in your application. The Command Model manages a command and the event it represents. On one hand it references the Command it manages on the other hand does it reference the View Model. Think of the Command Model as the mini-Controller for one Command. When the Command fires the Command Manager executes its handler code against the View Model, which might cause view updates (property changed notification).

During binding in the Data Templates the Command must be set to the Command property of the UI element. Note that Command instances can be declared static.

Unit Testing

Because the objects are bound to the view (and Data Templates) there is no dependency from the View Model or Data Model to the View or its UI elements. This means that the View Model, Data Model and Command Model objects can be unit tested very easily without having to resort to UI-record & replaying testing tools.

Wrapping up

My first experiments with this pattern were interesting: it takes a little getting used to and frequently I had to get above the code to see the (helicopter) overview to see what I was doing and were to put the code. I realize that this post might be a bit short and cryptic. I recommend reading the blog posts of Dan Crevier that also includes a sample application in its last post. I think I might have deviated a little from what Dan writes but the idea remains the same: Utilize the tremendous power of WPF data binding.

Trace Context Aspects with PostSharp

Marc Jacobi — Tue, 15 Apr 2008 13:47:41 GMT

In my previous post I wrote about a method context information gathering framework I wrote in an attempt to increase the amount of useful information in trace output and exceptions. In this final post about the framework I will discuss the use of a static aspect weaver PostSharp.

Static Aspect Weaving

I assume that you know what aspects are at least at a conceptual level. The nice thing about static aspects is that their code is injected at compile time, not at runtime. True: static aspects are not configurable, but they are completely transparent (dynamic aspects usually require the client code to create a proxy instead of the actual object).

I use PostSharp, a static aspect weaver, to implement a code attribute that triggers aspect code injection into the assembly. PostSharp works at IL level so it should be usable with any .NET language. While PostSharp provides a generic assembly manipulation framework, it is actually Laos that provides the aspect framework.

When an aspect (a code attribute) is applied to a method, PostSharp (actually Laos) rewrites the IL for that method. It basically relocates the original method IL in a new method with the same name, prefixed by a '~'. Then it inserts custom IL that performs the call sequence on your aspect object. Your aspect can be responsible for calling the actual method -using a delegate- (as it is in this example), although there are also flavors of aspects that do not require this.

So a typical (simplified) call stack would look something like this:

void MyClass.MyMethod(string param1)
void MyAspect.OnInvocation(MethodInvocationEventArgs eventArgs)
void delegate.DynamicInvoke(object[] parameters)
void MyClass.~MyMethod(string param1)

The stubbed MyClass.MyMethod routes execution to the aspect (OnInvocation) applied to the method and the aspect code invokes the delegate that point to the original method (or it doesn't ;-) and the original method (prefixed with ~) executes.

TraceContextAspect

In order to eliminate the custom code you'd have to write to use the TraceContext in our method context information gathering framework, I've created a PostSharp/Laos aspect class that intercepts the method call as described above. So instead of making all the calls to the TraceContext yourself in the method code, you simply apply the aspect to the method:

[TraceContextAspect]
public string PrintName(int numberOfTimes)
{
// method impl.
}

The TraceContextAspect implements the OnInvocation method like so:

using (AspectTraceContext ctx = new AspectTraceContext(_methodBase))
{
    ctx.Initialize(eventArgs.Delegate.Target);
    AddParameters(ctx, eventArgs.GetArguments());
    ctx.TraceMethodEntry();

    try
    {
        eventArgs.ReturnValue = eventArgs.Delegate.DynamicInvoke(eventArgs.GetArguments());

        ctx.SetReturnValue(eventArgs.ReturnValue);
    }
    catch (Exception e)
    {
        ctx.AddContextTo(e);
        throw;
    }
} // maintains stack and writes method exit and flushes writer.

Note that I've derived a new class from TraceContext for this specific situation (AspectTraceContext) that takes a MethodBase instance as a parameter in its constructor. The MethodBase instance is handed to you by the PostSharp/Laos framework and represent the method the aspect was placed on. The bold text is the actual call to the original method. As you can see, all the custom code needed to setup the TraceContext has now moved to the OnInvocation method implementation.

Conclusion

The use of a static aspect weaver has dramatically simplified the usage of the method context information gathering framework. Tracing useful and rich information from your method has now become a breeze (as it should be ;-).

I hope these last 3 post has shown you how you can leverage existing technology (System.Diagnostics and PostSharp) to make the most out your own tracing framework (in this case). I also hope you will be inspired to find new applications to use static aspects in your own code. I find that static aspects can really make your life easier while at the same time not making your code (execution paths) more complicated than needed.

You can download the source code here.

A Method Context Information Gathering Framework

Marc Jacobi — Sat, 12 Apr 2008 13:31:00 GMT

Do you also have that feeling when you type in your tracing code that it is too cumbersome and too much hassle to get it right? I mean really trace the information that is useful for finding faults, for instance. And when you log an exception, even when you write out all the information the exception offers, it is barely enough to really understand what went wrong?

That is why I wrote this framework. This framework tries to solve one major problem (and some small one on the side): Getting the runtime information of an executing method into a trace text or an exception.

Note that this post assumes you know about the main classes in System.Diagnostics.

MethodContext

The MethodContext is a class that maintains all running values during the execution of a method. It is created at the beginning of the method and it is Disposed at the end of the method. It collects information about the runtime values of the method parameters, the class reference (this) if it isn't a static method and its return value. This runtime method context information can be formatted into trace texts or added to an exception the code is about to throw.

The MethodContext also maintains its own call stack and provides access to its calling method context.

For tracing purposes a MethodContext derived class, the TraceContext, adds to this a reference to a MethodTracer and method entry and exit trace methods.

Here's a typical usage scenario:

public string Repeat(string value, int numberOfTimes)
{
    using(TraceContext ctx = new TraceContext())
    {
        ctx.Initialize(this);
        ctx.AddParameter(value, "value");
        ctx.AddParameter(numberOfTimes, "numberOfTimes");
        ctx.TraceMethodEntry();

        string result = null;

        // method impl.

        ctx.ReturnValue = result;

        return result;
    } // Dispose is called on ctx, calling TraceMethodExit()
}

Note that the TraceContext (MethodContext) maintains weak references to all instances.

MethodTracer

The MethodTracer instance is created for each TraceContext. The MethodTracer takes a TraceSource and an optional method-level TraceSwitch in its constructor and uses these to filter and output trace text. It implements 2 versions of the FormatTrace method; one instance and one static. The static FormatTrace method can be used by your code to trace custom texts. The TraceContext is located behind the scenes.

The FormatTrace method takes an object parameter as the object to generate a trace text for (along with some other parameters). The method delegates this task to the TraceManager (discussed next) where a collection of ITraceFormatter instances is checked to see if that specific Type is supported.

If the TraceSwitch allows it the formatted text is output to the TraceSource.

TraceManager

The TraceManager is a global (singleton) class that manages several cached classes. One already discussed are the TraceFormatters. These classes are able to generate trace text for a specific Type of object. TraceFormatters can use other TraceFormatters and thus composing the trace text.

By convention the TraceManager will keep track of a TraceSource for each class Type that creates a TraceContext. It will also keep track of optional method TraceSwitch instances that can be configured to fine tune trace levels at method level.

Exceptions

Exceptions caught in the method that created a TraceContext can keep track of it using the LastError property on the context. When throwing exceptions you can add the context information of the TraceContext to the exception using the AddContextTo method. This method populates the Data dictionary of an exception instance with the context information. Note that only types that are serializable are added, this is because the Data dictionary doesn't allow otherwise (exceptions need to be marshaled across boundaries sometimes and that involves serialization).

The following code sample shows a nice way to add runtime information to an exception before propagating it to a higher level.

public string ReadTextFile(string path)
{
    using(TraceContext ctx = new TraceContext())
    {
        ctx.Initialize(this);
        ctx.AddParameter(path, "path");
        ctx.TraceMethodEntry();

        string result = null;

        try
        {
            // method impl.
        }
        catch(IOException ioe)
        {
            ctx.AddContextTo(ioe);
            throw;
        }

        ctx.ReturnValue = result;

        return result;
    } // Dispose is called on ctx, calling TraceMethodExit()
}

The calling code will receive an exception which Data dictionary is filled with runtime method context information. A nice extension would be to be able to dump all properties of the instances present in the Data dictionary. That way you should be able to generate comprehensive error log messages.

Configuration

The following configuration shows how to set up a Console TraceListener and an EventLog TraceListener for errors, a trace source for several classes, trace switches at class level (trace source) and at method level.

Basically this configuration is very similar to the one discussed in my previous post about System.Diagnostics. <sharedListeners> declares all listeners, <sources> lists a TraceSource per class and <switches> configures both class-level switches and method-level switches. Notice that the method level switches extent the dot-syntax with the method name for the name of the switch and carry an extra traceFlow attribute. The traceFlow attribute allows you to filter the output of method entry and exit traces that are done by the TraceMethodEntry and TraceMethodExit methods on TraceContext.

The next post will investigate a way to get rid of all the custom code you have to write to use the TraceContext. Using a static aspect weaver it is possible to have all that code removed from your method and indicate with a code attribute what methods you want to trace in a completely transparent way.

Download the source code here. Note that this source code also contains the projects for the static aspect weaver that will be discussed in the next post.

Basic System.Diagnostics

Marc Jacobi — Fri, 04 Apr 2008 18:44:00 GMT

The .NET framework has shipped with the System.Diagnostics namespace since version 1.0. My efforts to build a method context information gathering framework on the services of System.Diagnostics has brought me a deeper understanding of its classes and configuration settings. I will talk about my method context information gathering framework in a later post, but first I thought I would get us all on the same page on System.Diagnostics.

System.Diagnostics implements several classes that play a key role in outputting trace text from your application. Better understanding these classes will bring you insights in to how to extend the existing diagnostic framework in .NET or how to set up the configuration file to make full use of the out-of-the-box functionality.

TraceListener

The TraceListener class receives trace texts from the application and outputs it to a specific channel it was written for. There is a DefaultTraceListener class that outputs its text to the Win32 API OutputDebugString. But there is also an EventLogTraceListener that outputs its text to the windows event log. There is even an XmlWriterTraceListener that will output Xml to a stream. There are more listeners you can choose from and you can even write your own. Just derive your listener class from the abstract TraceListener base class and implement the abstract methods.

A TraceListener also maintains an optional Filter. This allows you to fine tune the type of information that a TraceListener actually outputs. For instance, you could put an EventTypeFilter on the EventLogTraceListener to only output Error-type traces to the windows event log.

TraceListener instances are held in a collection that all receive the same trace text to output. This means that the same trace text can be output on different channels (each channel is represented by a TraceListener) at the same time. This collection can live at the global/static Trace or Debug classes or at a TraceSource.

TraceSource

A TraceSource represents a configurable trace object that maintains its own set of TraceListeners. An associated TraceSwitch (discussed next) controls the trace level for this 'scope'. Typically a TraceSource is configured in the .config. When the code instantiates a TraceSource with the same name it reads its settings from the .config file. This way you can control what portions of your application code will output trace text.

TraceSwitch

A TraceSwitch maintains a TraceLevel property that controls the importance of the trace texts passed to the TraceListeners. The usual Error, Warning, Info and Verbose are supported. Typical use is to configure the TraceSwitch in the .config file and when the code instantiates an instance using the same name it reads its settings from the .config file. Although you can use TraceSwitches standalone they are usually associated with a TraceSource (in config). It is also possible to write your own TraceSwitch.

Configuration Settings

A lot of System.Diagnostics functionality is driven by the .config file. Lets dive right in and look at the following configuration:

The configuration settings live inside the <system.diagnostics> element. Then we see a <sharedListeners> section. Although it is possible to configure all TraceListener settings separately for each TraceSource, I prefer to maintain a global list of (configured) TraceListeners and refer to them from the TraceSource configuration. <sharedListeners> is that global place. Notice that the EventLogTraceListener has a <filter> defined that only allows Error-type traces to pass to the event log.

The <sources> section allows you to list the configuration settings for all the TraceSources your application uses. If the configuration for an instantiated TraceSource is not found in the .config file, it is shut off by default. So if you expect to see trace output from a specific TraceSource but there isn't any, 9 out of 10 times you did not configure it right (check the spelling).

Each <source> declares its own collection of TraceListeners, in this case referring to one declared in <sharedListeners>. As a convention I've used the full class names as TraceSource names and TraceSwitch names. But you can also choose a courser granularity, say at component level or at sub-system level.

You can associate a TraceSwitch with a TraceSource by using the switchName and switchType attributes on the <source> element. I've not done so in my example and that means that you have to instantiate the TraceSwitches manually in code (with the correct name). You can associate a TraceSwitch with a TraceSource by either using the switchName and switchType attributes on the <source> element -or- by just declaring a switch (<switches><add>) with the same name as the TraceSource.

Wrapping up

This quick tour around System.Diagnostics discussed the main classes that enable you to build pretty powerful tracing support into your application. With this information you could already instantiate a TraceSource for each class and configure a matching TraceSwitch. Code inside the class would simply call the TraceSource and it would work. You could configure it to allow specific (type of) information to come through while the rest is blocked, for instance. And although I would encourage anybody to at least take some time to fiddle with a simple console test application to try out these features, it is my experience that you'll want more in a real application. That is why I build my method context information gathering framework. Although this framework does not add much to the tracing capabilities of System.Diagnostics, it does add a lot to the quality of information that is in the trace texts.

I plan to write about my framework in a future post.

For more information on System.Diagnostics go to MSDN.

Writing a WCF POX Syndication Service

Marc Jacobi — Thu, 03 Apr 2008 19:59:00 GMT

WCF has received some enhancements in the .NET 3.5 framework. It is now possible to use the WCF service framwork to write POX services; a service that does not use SOAP, but Plain Old Xml.

Also the Syndication support for WCF is new to .NET 3.5. It has builtin support to produce Rss 2.0 and Atom 1.0 feeds.

The example I like to show you is an Event Log Feed Service. This service produces a Rss 2.0 feed for the Application event log Error entries. It is hosted in IIS and can be called by addressing it over the url:

http://[base url]/Service.svc/GetLogEntries

Notice the GetLogEntries after the Service.svc. The GetLogEntries maps to the GetLogEntries method of the service and takes two optional parameters: an entryType (Error, Warning, Information) and a feedType (Rss1, Atom1).

http://[base url]/Service.svc/GetLogEntries?feedType=atom1
http://[base url]/Service.svc/GetLogEntries?entryType=Warning&feedType=atom1

To look at this for yourself download the source code here and install the service in IIS. Make sure the service dll is in the web's bin folder.

The Service interface is declared using WFC's ServiceContract attribute.

[ServiceKnownType(typeof(Atom10FeedFormatter))]
[ServiceKnownType(typeof(Rss20FeedFormatter))]
[ServiceContract]
public interface IEventFeedService
{
    [WebGet(UriTemplate="/GetLogEntries?eventType={eventType}&feedType={feedType}")]
    [OperationContract]
    SyndicationFeedFormatter<SyndicationFeed> GetLogEntries(string eventType, string feedType);
}

The return types are declare with using the ServiceKnownType attribute. The WebGet attribute makes it possible to call this service using the url (GET). The UriTemplate declares what possible variation are supported on the url: the method name and its optional parameters. Note that the parameter names of the method match the parameter names in the UriTemplate.

The Service implementation class implements the method of the Service interface (refer to the dowload for complete source code). Creating the Syndication Feed is a matter of creating SyndicationFeedItem instances and adding them to a SyndicationFeed instance. Finally the method returns either a Rss20FeedFormatter or a Atom10FeedFormatter instance depending on the requested feed format.

The Service.svc file is used by IIS to determine how to host the service.

<%@ServiceHost Factory="System.ServiceModel.Web.WebServiceHostFactory" Service="EventLogFeedService.EventFeedService" %>

Besides specifying which service class should be hosted, the file also specifies a Factory to create a WCF service Host instance. Note that this is a new class that supports the url addressing of our WebGet enabled service.

Disclaimer: Exposing event log information to external sources can expose a security hole!

7 WCF/SOA Tips

Marc Jacobi — Sat, 29 Mar 2008 15:48:00 GMT

David Pallman gives 7 WCF and SOA tips. Not all rocket science but interesting non-theless.