MSMQ Distributor Service Exceptions

Topics: Logging Application Block
Jan 4, 2012 at 9:15 PM

Hi,

I have an application that logs using the MSMQ Trace Listener to a queue.  The MSMQ Distributor Service is correctly installed and messages appear in the queue and are written out to log files, no problem.  However, using the Windows Performance Monitoring tool we can see that every time the distributor service wakes up to check the queue it throws an exception.  However, the exception does not appear in the Applicatin Event logs, as the other distributor service messages do.  I am suspecting that the MsmqLogDistributor code is eating an exception and not logging it to the Event logs, but clearly Windows CLR is detecting the exception.  The frequency of the exceptions is directly related to the queue timer interval, as in if I change that value then that's also when I see the exception reported in the Windows performance monitor tool, but not in the event logs.  I Tried debugging the service in VS2010, but ran into symbol issues, etc.  Any ideas?

 

Thanks,
MG

Jan 4, 2012 at 10:38 PM
Edited Jan 5, 2012 at 4:42 AM

So, I was able to build the service from source and attach the visual studio debugger to the it and identified the culprit code.  There is a while() loop in ReceiveQueuedMessages() that calls a method continuously to see if there is anything in the queue.  That method looks like this:

       private bool IsQueueEmpty()
        {
            bool empty = false;
            try
            {
                using (MessageQueue msmq = CreateMessageQueue())
                {
                    msmq.Peek(new TimeSpan(0));
                }
            }
            catch (MessageQueueException e)
            {
                if (e.MessageQueueErrorCode == MessageQueueErrorCode.IOTimeout)
                {
                    empty = true;
                }
            }

            return empty;
        }
I did a bit of research and it seems that trying to see if there are messages
in the queue is not an easy thing to do, and saw references to using Peek() with
a zero-timer timeout as an implementation of checking the queue status.
Jan 5, 2012 at 1:53 AM

The loop is while(!IsQueueEmpty()).  This just processes all of the messages in the queue.  Once the queue is empty then the method exits until the next time the timer fires.

Can you find out what exception is being thrown?

Do you see messages in the event log for the service starting such as "The queue listener has started successfully. Note: the listener timer is set to [{0}] milliseconds."?

Most exceptions are thrown and caught which cause the service to shutdown.  However, if you encounter a FormatException or a SerializationException then those exceptions are swallowed.  However they should be logged to the event log (which is why I asked if you see other messages from the Distributor Service in the event log).  The default source is "Enterprise Library Logging Distributor Service". 

Just curious what counters you are monitoring in perfmon to see the exceptions?

--
Randy Levy
Enterprise Library support engineer
entlib.support@live.com 

Jan 5, 2012 at 4:19 AM
Edited Jan 5, 2012 at 4:36 AM

 

Thanks Randy.  Yeah, the exception is an IOTimeOut one that is thrown when TimeSpan(0) is called as a parameter to Peek().  If you notice in the try/catch block that I quoted, the exception is caught but nothing is logged or propagated.  It's a bit unorthodox perhaps to use exception handling as part of the implementation of the logic, but I have seen other references to this method as it pertains to the checking of the queue for messages.

There are other messages in the event log from the service, so it's all behaving as designed.  The way we noticed the exception was in setting up a performance monitor counter.  The specific monitor that we set up was an instance of the .Net CLR Exceptions, specifically the # of .Net CLR Exceptions Thrown Per Second for the MSMQ Distributor service instance.  We saw that whatever time interval we set the service to check for the queue in the config file, that an exception was thrown at the same rate.  Digging into the code thus revealed the source of that exception, i.e. the IOTimeOut when Peek(new TimeSpan(0)) is invoked when the check is made to see if queue is empty or not.

 

Thanks,

Jan 5, 2012 at 4:35 AM

The behavior seems to be by design.  A MessageQueueException with a MessageQueueErrorCode equal to IOTimeout will be thrown if there is nothing in the queue (the Peek times out since there was nothing to peek).  From MSDN documentation for MessageQueueErrorCode Enumeration:

Message Queuing returns this error if the time-out specified in a call to MessageQueue.Receive or MessageQueue.Peek expires before a new message arrives in the queue. This can only happen if there was no message already in the queue; both methods would return immediately if a message exists.

It looks to be valid to ignore this exception.

--
Randy Levy
Enterprise Library support engineer
entlib.support@live.com 

Jan 5, 2012 at 4:40 AM

Right, it is by design.  Thanks for the MSDN references. 

Curious though if there are any performance penalties in having to have to go through the exception handling process for that queue check?


Thanks

Mohsen

Jan 5, 2012 at 3:18 PM

Well, throwing an exception is expensive so it's not optimal.  But in this case the exception is only thrown when there is nothing in the queue and after the exception is handled the service is going to go back to sleep until the timer fires again (the default is 20 seconds),  So practically, as long as the timer is not set to an extremely small number, there should be very little performance impact.

Also, if there is heavy activity and the queue is constantly being populated then it looks like the exception will never be thrown since there will always be messages to Peek at.

--
Randy Levy
Enterprise Library support engineer
entlib.support@live.com

<!--[if gte mso 9]><xml> <w:WordDocument> <w:View>Normal</w:View> <w:Zoom>0</w:Zoom> <w:PunctuationKerning /> <w:ValidateAgainstSchemas /> <w:SaveIfXMLInvalid>false</w:SaveIfXMLInvalid> <w:IgnoreMixedContent>false</w:IgnoreMixedContent> <w:AlwaysShowPlaceholderText>false</w:AlwaysShowPlaceholderText> <w:Compatibility> <w:BreakWrappedTables /> <w:SnapToGridInCell /> <w:WrapTextWithPunct /> <w:UseAsianBreakRules /> <w:DontGrowAutofit /> </w:Compatibility> <w:BrowserLevel>MicrosoftInternetExplorer4</w:BrowserLevel> </w:WordDocument> </xml><![endif]--><!--[if gte mso 9]><xml> <w:LatentStyles DefLockedState="false" LatentStyleCount="156"> </w:LatentStyles> </xml><![endif]--><!--[if gte mso 10]> <mce:style><! /* Style Definitions */ table.MsoNormalTable {mso-style-name:"Table Normal"; mso-tstyle-rowband-size:0; mso-tstyle-colband-size:0; mso-style-noshow:yes; mso-style-parent:""; mso-padding-alt:0cm 5.4pt 0cm 5.4pt; mso-para-margin:0cm; mso-para-margin-bottom:.0001pt; mso-pagination:widow-orphan; font-size:10.0pt; font-family:"Times New Roman"; mso-ansi-language:#0400; mso-fareast-language:#0400; mso-bidi-language:#0400;} --> <!--[endif] -->

--
Randy Levy
Enterprise Library support engineer
entlib.support@live.com