Thursday, February 17, 2011

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. SmileSmile 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.

1 comment:

Anonymous said...

Oh man, this was both funny and informative!
Thanks, it saved me hours of frustration.