I have a WCF service that is utilizing the msmq binding to get messages from
a client (self hosted). The server reads the queue and makes the proper
operation calls no problem.
However, in my tests, when I add one message to the queue, a second thread
picks up that same message (based on the LookupId) and starts processing it
before the first thread is done!
I have TransactionScopeRequired=ture for the operation (and autocomplete is
also true), so I don't understand why another thread is picking up the same
message. Shouldn't the message be pulled off the queue when it is being
processed such that no other thread can see it (and I understand it gets
replaced if the transaction aborts)?
For the below dump: The operation name is "Send Log", and it takes an XML
parameter and sends it to a DB via a stored proc. In this example, I send
invalid XML to cause the service to retry the message until it fires a
poisoned message exception (which I have attached a custom handler to).
The new thread appears to attempt to pick up the same message before the
first one comes back from the SP call (I've validated this in the debugger,
even earlier than the actual SP call). I'm not sure what else to do. Here's
a dump of my manual logs. Not sure it will be clear to anyone reading them,
but maybe it will.
Thanks for any ideas:
{Thread:1} Company.Services.Logging.Host is starting...
{Thread:1} Checking MSMQ (.\private$\companyloggingtester)...
{Thread:1} Queue ready
{Thread:1} Starting WCF service host...
{Thread:1} -- Host open and ready for service calls --
{Thread:3} [Send Log]
{Thread:3} Processing Message:504403158265505899
{Thread:3} Params:2, MSMQ Logger Test, <XMLDATA>my broken XML
{Thread:3} SQL conn created
{Thread:3} SQL cmd created
{Thread:3} SQL conn open
{Thread:3} Executing SP...
{Thread:4} [Send Log]
{Thread:4} Processing Message:504403158265505899
{Thread:4} Params:2, MSMQ Logger Test, <XMLDATA>my broken XML
{Thread:4} SQL conn created
{Thread:4} SQL cmd created
{Thread:4} SQL conn open
{Thread:4} Executing SP...
{Thread:3} [Handle Error]
{Thread:3} Error: XML parsing: line 1, character 22, unexpected end of
input
{Thread:4} [Handle Error]
{Thread:3} [Send Log]
{Thread:4} Error: XML parsing: line 1, character 22, unexpected end of
input
{Thread:3} Processing Message:504403158265505899
{Thread:3} Params:2, MSMQ Logger Test, <XMLDATA>my broken XML
{Thread:3} SQL conn created
{Thread:3} SQL cmd created
{Thread:3} SQL conn open
{Thread:3} Executing SP...
{Thread:3} [Handle Error]
{Thread:4} [Send Log]
{Thread:3} Error: XML parsing: line 1, character 22, unexpected end of
input
{Thread:4} Processing Message:504403158265505899
{Thread:4} Params:2, MSMQ Logger Test, <XMLDATA>my broken XML
{Thread:4} SQL conn created
{Thread:4} SQL cmd created
{Thread:4} SQL conn open
{Thread:4} Executing SP...
{Thread:4} [Handle Error]
{Thread:4} Error: XML parsing: line 1, character 22, unexpected end of
input
{Thread:3} Host Faulted... waiting for 00:00:15 seconds and then restarting...
{Thread:3} [Handle Error]
{Thread:3} Poisoned message: 504403158265505899
{Thread:3} Removing poisoned message from the queue [504403158265505899]
{Thread:8} Landstar.Services.Logging.Host is restarting...
{Thread:8} Checking MSMQ (.\private$\landstarloggingtester)...
{Thread:8} Queue ready
{Thread:8} Starting WCF service host...
{Thread:8} -- Host open and ready for service calls --