WCF–maxSizeOfMessageToLog and "Message not logged because its size exceeds configured quota"

I’m always in for investigating some features that smell of a bad design. And though I believe WCF is a very solid piece of a framework, this warning message while skipping the message log makes me nervous. By itself surely it is better to have an ability to skip logging messages over threshold size, but if I made my conscious decision through configuration for that size, why should I still be given a warning?
I’m used to log warnings and up into EventLog for admins to be alerted. This warning just makes my admins alerted for nothing. Not good.

So I wanted to see if I can tame this in some legitimate way. I started with msdn:

http://msdn.microsoft.com/en-us/library/system.servicemodel.configuration.messageloggingelement.maxsizeofmessagetolog.aspx

Which by the way states about maxSizeOfMessageToLog the following: "The maximum size, in bytes, of a message to log. Messages larger than the limit are not logged. This setting affects all trace levels. The default is Int32.MaxValue"

Int32.MaxValue??!! This would not be corresponding to any “secure by default” and to the real life experience working with wcf! So dive into the reflector shows:

 

internal MessageLogTraceRecord(Stream stream, MessageLoggingSource source) : this(source)

{

    this.type = null;

    StringBuilder builder = new StringBuilder();

    StreamReader reader = new StreamReader(stream);

    int size = 0x1000;

    char[] buffer = DiagnosticUtility.Utility.AllocateCharArray(size);

    int maxMessageSize = MessageLogger.MaxMessageSize;

    if (-1 == maxMessageSize)

    {

        maxMessageSize = 0x1000;

    }

    while (maxMessageSize > 0)

    {

        int num3 = reader.Read(buffer, 0, size);

        if (num3 == 0)

        {

            break;

        }

        int charCount = (maxMessageSize < num3) ? maxMessageSize : num3;

        builder.Append(buffer, 0, charCount);

        maxMessageSize -= num3;

    }

    reader.Close();

    this.messageString = builder.ToString();

}

As we see above the origins of the default value are found in the MessageLogTraceRecord with its value of 4096 bytes as per above (which is quite reasonable I think).

As it often happens bad smells are coming in batches, so we can see in TraceXPathNavigator which is used by PlainXmlWriter (all in System.ServiceModel?.Diagnostics namespace) how “business” case of exceeding the threshold is handled via exception:

private void VerifySize(int nodeSize)

{   

  if ((this.maxSize != -1) && ((this.currentSize + nodeSize) > this.maxSize))  

  {      

    throw new PlainXmlWriter.MaxSizeExceededException();    

  }  

    this.currentSize += nodeSize;

  }

 

And now to complete the parade this exception is handled by creation of a Warning message in System.ServiceModel.Diagnostics.MessageLogger LogInternal method:

catch (PlainXmlWriter.MaxSizeExceededException)

    {

        if (DiagnosticUtility.ShouldTraceWarning)

        {

            TraceUtility.TraceEvent(TraceEventType.Warning, TraceCode.MessageNotLoggedQuotaExceeded, record.Message);

        }

    }

This is quite far from any good design choice in my opinion! By bet is that this guy has moved from WCF team to Silverlight’s already. But before he did that, he made it sure we have no legitimate way to avoid that warning message and probably didn’t tell the truth to the msisdn documentation team.

Silverlight – my dumb blonde partner.

Reading a book on Silverlight 3.0 right now and can’t stop from getting excited from time to time – how is it possible that with all the validation guidance from WPF and ASP.NET MVC somebody in MS just returned back 10 years and provided a pattern of validation via exceptions for Silverlight??!!

Can the justification possibly be that it was too much of bytes to incorporate IDataError pattern from WPF? I’m afraid it is a “blond” factor and not amount of bytes behind that design.

Look at this code from Brad Adams’s blog with title “Design Guidelines, Managed code and the .NET Framework” (http://blogs.msdn.com/brada/archive/2009/07/24/business-apps-example-for-silverlight-3-rtm-and-net-ria-services-july-update-part-11-the-client-only-world.aspx):

        [DataMember()]

        [Key()]

        [ReadOnly(true)]

        public int EmployeeID

        {

            get

            {

                return this._employeeID;

            }

            set

            {

                if ((this._employeeID != value))

                {

                    ValidationContext context = new ValidationContext(this, null, null);

                    context.MemberName = "EmployeeID";

                    Validator.ValidateProperty(value, context);

                    this._employeeID = value;

                    this.OnPropertyChanged("EmployeeID");

                }

            }

        }

And Validator.ValidateProperty(value, context) throws an exception so SL controls can apply templates for invalid data.

Both the code above and design concept are more than ugly (from many viewpoints) and are a huge design step back compared to asp.net mvc and wpf. Shame!

Nothing that can’t be worked around / substituted, but the payload of dead bytes from the “dumb blonde” designer will still be there.

Event Stream Processing (ESP). Java got it all, where does .NET guy go?

I'm a great believer in enterprise wide distributed events and traces/logs processing.

One of my personal projects that I abandoned few years ago was focused on the distributed tracing/logging, visualizing the traces and providing trivial correlation analysis.

I'm trying to reanimate it right now, so I looked around to avoid the wheel reinvention and found out that as I was reading only .NET news for the last few years I totally missed the evolution of Event Stream Processing in the Java world. It is apparent to me now that it is what I want, BUT there is no .NET story for it. Or should I say there is always some kind of a story?

There is a Java open source project named ESPER and there is its .NET clone named NESPER, both licensed under GPL. Other licensing options? - exist, but with a price tag deeply hidden. When we talk about a .NET clone we should say if this is a .NET code it was compiled from or it is just a conversion from the java byte-code.

In the case of NESPER it is the latter option which makes it very hard to recommend in real enterprise applications (at least from my viewpoint). Another example is Drools.NET, go and offer you customer rule engine which they can't really change/fix regardless its open source character as change would require a java recompile following the byte-code conversion (and this is not anything for faint of heart which customers normally are). Normally it chains you to some older version that you have been lucky enough to get converted from java byte-code once.

As it looks, there is no 1st class citizen ESP/CEP solution in .NET. It leaves me pretty with a blank piece of paper to start with and I'll just implement something very, very lightweight. Although it was a very good read on the ESP to understand the domain, see the basic requirements and challenges.

Few links I found interesting are:

Who is who and what is what in the ESP and CEP (complex event processing) - http://complexevents.com/. I'd start from this link and drill down. At this early stage I found the glossary there to be very good (EPTS Event Processing Glossary v1.1), but I'll be digging more, place has got a value.

ESPER documentation http://esper.codehaus.org/esper-2.1.0/doc/reference/en/pdf/esper_reference.pdf
Discussion on msdn forum: http://social.msdn.microsoft.com/Forums/en-US/netfxbcl/thread/c0582ebb-1a4e-49ed-ab4e-a8b614643bdc/.
Provides more technical view on the subject and helps to fill the gap between the business domain from the above mentioned glossary and the implementation domain.

An article on ESPER I found interesting to read: http://www.onjava.com/pub/a/onjava/2007/03/07/esper-event-stream-processing-and-correlation.html

InfoQ on ESPER, but mostly on the performance/throughput promises of different engines: http://www.infoq.com/news/2007/10/esper

Very concise review of ESP and CEP: http://www.eventstreamprocessing.com/, only good if you don't want to dedicate more than 10 minutes to the subject.

---

My addiction to instrumentation, logs and traces makes me a "service-level agreement" user according to the ESP/CEP areas of applicability classification. I'm fascinated how simple SLA abbreviation hides all that fun and hard work you do to make your application available, maintainable and fast. But I guess, that is how business people see it :)!

Now I need to map what I learned to my simplified requirements (and I didn't want to keep them that simple!) and .NET technology stack available. Will be back with analysis!

Testing the composite pattern - reusable test helpers

I face quite often the need to test a composite pattern variations. And truly was duplicating some similar code around. As tests are now my focus for self-improvement (and always, should I be eaten alive by the tdd purists if I lie), I decided to extract some of the snippets into reusable helper methods.
Here is what I got for the calling of the composite pattern "operation":

The usage:

CompositePatternTestHelper.TestForCompositeOperation<ProcessCoordinator, IProcess>(

                parent => parent.Stop(), // Parent operation

                child => child.Stop(), // Should invoke following on every child

                (parent, child) => parent.Processes.Add(child) // How to add add child to the parent

                );

And for the helper method/class implementation (The most recent version available at http://code.google.com/p/toolsdotnet/source/browse/trunk/Tools.Net/src/Tools.Tests.Helpers/CompositePatternTestHelper.cs):

using System;

using Rhino.Mocks;

namespace Tools.Tests.Helpers

{

    public static class CompositePatternTestHelper

    {

        /// <summary>

        /// Helper method to test composite [parent/child] pattern implementation, where calls

        /// to the parent result into calls onto its children.

        /// </summary>

        /// <remarks>Creates the parent object using its default constructor</remarks>

        public static void TestForCompositeOperation<ParentType, ChildType>(Action<ParentType> parentAction, Action<ChildType> childAction, Action<ParentType, ChildType> addChild)

            where ChildType : class

            where ParentType : new()

        {

            // Requires a default ctor to exists

            var parent = new ParentType();

            TestForCompositeOperation(parent, parentAction, childAction, addChild);

        }

        /// <summary>

        /// Helper method to test composite [parent/child] pattern implementation, where calls

        /// to the parent result into calls onto its children.

        /// </summary>

        /// <remarks>Uses the passed in instance of a parent</remarks>

        public static void TestForCompositeOperation<ParentType, ChildType>(ParentType parent, 

            Action<ParentType> parentAction, Action<ChildType> childAction, Action<ParentType, ChildType> addChild)

            where ChildType : class

        {

            // Use Rhino.Mocks to create stubs

            var child1 = MockRepository.GenerateStub<ChildType>();

            var child2 = MockRepository.GenerateStub<ChildType>();

            // Setup two children, the arbitrary choice, but should not really matter

            child1.Expect(childAction);

            child1.Expect(childAction);

            // Add children to the parent

            addChild(parent, child1);

            addChild(parent, child1);

            // Call parent action

            parentAction(parent);

            // Assert parent action resulted in the calls to children

            child1.AssertWasCalled(childAction);

            child1.AssertWasCalled(childAction);

        }

    }

}

Design for testability - testing asynchronous method with callback. Strategy pattern to the rescue!

Implementations of asynchronous pattern can differ, in this entry I decided to share my observations on design features required to make it more testable. Lets take a sample (please note that synchronization on the param is omitted to simplify the scope and real implementation would have to volatile/synchronize):

public class AsyncBench

    {

        private int param;

        internal int Param { get { return param; } }

        public AsyncBench(int param)

        {

            this.param = param;

        }

        public void BeginMethod()

        {

            Func<int, int> method = Method;

            IAsyncResult ar = method.BeginInvoke(Param, AsyncMethodCallback, new State {Field = 10});

        }

        private int Method(int param)

        {

            return param + 1;

        }

        public void AsyncMethodCallback(IAsyncResult ar)

        {

            var asyncResult = ar as AsyncResult;

            try

            {

                param = (asyncResult.AsyncDelegate as Func<int, int>).EndInvoke(ar);

            }

            catch (Exception)

            {

                throw;

            }

        }

    }

    public class State { public int Field { get; set; } }

While this implementation can be totally suitable for some contexts, it lacks some important points from the testability perspective.
We want to be able to verify that Method is called and that Callback is setting the result right.
We also want to be able to wait for the Method to be executed. The solution I found for this is to adjust the implementation towards the Strategy pattern and follow more the pattern of Begin[Method], End[Method]. The current sample is based onto callback (End[Method] would represent a slight variation).
The amended code looks like:

public class AsyncBench

    {

        private int param;

        internal int Param { get { return param;}}

        internal readonly Func<int, int> method;

        public AsyncBench(int param)

        {

            this.param = param;

            this.method = Method;

        }

        public AsyncBench(int param, Func<int, int> method) : this(param)

        {

            this.method = method;

        }

        public IAsyncResult BeginMethod()

        {

            return method.BeginInvoke(param, AsyncMethodCallback, new State {Field = param});

        }

        private int Method(int n)

        {

            return n + 1;

        }

        public void AsyncMethodCallback(IAsyncResult ar)

        {

            var asyncResult = ar as AsyncResult;

            try

            {

                param = (asyncResult.AsyncDelegate as Func<int, int>).EndInvoke(ar);

            }

            catch (Exception)

            {

                throw;

            }

        }

    }

    public class State { public int Field { get; set; } }

Main differences are that BeginMethod returns IAsyncResult so we can let our unit test to wait until the method completion. Method to call is not hardcoded anymore with default value though pointing still to the former Method.
Our test then consists of two methods. One to verify that method is called:

[TestMethod]

        public void BeginMethodTest()

        {

            bool methodCalled = false;

            // setup the method

            Func<int, int> method = (n) =>

                                        {

                                            methodCalled = true;

                                            return -1;

                                        };

            // setup the test instance

            var asyncSample = new AsyncBench(

                20, method);

            IAsyncResult ar = asyncSample.BeginMethod();

            // wait until method call completes

            ar.AsyncWaitHandle.WaitOne();

            // verify it is completed

            Assert.IsTrue(ar.IsCompleted, "Operation should have completed before reaching this point!");

            // verify our delegate was called

            Assert.IsTrue(methodCalled, "Test method should have been called, but it was not!");

            // The bellow assert would require more synchronization and exceeds the testing contract

            //Assert.AreEqual(-1, asyncSample.Param);

        }

And another one to see that callback is doing its job:

[TestMethod]

        public void AsyncMethodCallbackTest()

        {

            bool methodCalled = false;

            // setup method

            Func<int, int> method = (n) =>

            {

                methodCalled = true;

                return -1;

            };

            // setup test instance

            var asyncSample = new AsyncBench(

                20, method);

            IAsyncResult ar = method.BeginInvoke(20, null, new State {Field = 10});

            // wait for the method to complete

            ar.AsyncWaitHandle.WaitOne();

            // verify it has completed

            Assert.IsTrue(ar.IsCompleted, "Operation should have completed before reaching this point!");

            // and was really called

            Assert.IsTrue(methodCalled, "Test method should have been called, but it was not!");

            // use IAsyncResult from our own BeginInvoke for the callback on the test instance

            asyncSample.AsyncMethodCallback(ar);

            // check that EndInvoke worked as expected

            Assert.AreEqual(-1, asyncSample.Param);

        }

Examples provided are very simplistic and just point into common ways I've been pushed to when testing my async methods.
Also in some places I used public or internal accessibility where private could/should have been used, but I just wanted to avoid usage of private accessors for those short samples.

Notes to self - Producer/Consumer pattern

Short note to self for implementing the producer-consumer pattern

Structure to use for the internal "queue".

The right structure to use for the internal work item storage is queue and not stack based. In case when producers are fast they will always top the LIFO structure with work items so consumers will pick up first x from the top. That has got serious consequences in holding up transactional resources by increasing the average time of dispatch (across items) from the in-memory "storage". Plus bottom items may be picked after their transaction timeout has ended.

If still index-access structure is required (when internal array is used as a submission queue as well) then

Notification on unit of work.

When using Monitor.Pulse, Monitor.Wait for prompt dispatching and synchronization. The start time of the producer and consumer should be taken into consideration, if producer issues any Monitor.Pulse before consumer does Monitor.Wait, those Pulse are going to be lost. It would be better not to use this mechanism at all.

---

This is all trivial, just making notes to self.