Exception - Stack trace line number and message do not match

Question

We're seeing an odd issue with some of our code when things go awry - in certain circumstances, the exception message and the stack trace don't match up.

We have a number of message handlers with similar structure, like the following:

public void Handle(AddTelephoneNumber message)
{
    var directory = ClientService.Directory(Context).Result;

    var client = ClientService.ClientLookup(message.ClientNumber, Context).Result;
    if (!client.Item1)
    {
        //Client does not exist
        throw new Exception("Unable to locate client"); //A
    }
    //B Start
    var clientPersonsLnk = client.Item2.Links.Single(l => l.Rel == "client-persons");
    var persons = ClientService.Get<Persons>(clientPersonsLnk.Uri, Context).Result;
    var person = ClientService.Get<Person>(persons.PartyUri(message.Party), Context).Result;
    var phones = ClientService.Get<TelephoneNumbers>(person.Links.Single(l => l.Rel == "person-telephones").Uri, Context).Result;
    var addPhoneLink = phones.Links.Single(l => l.Rel == "telephone-add");

    var newPhone = new TelephoneNumber();
    //Set up the new telephone number, elided from sample
    //B End

    var result = ClientService.Post(addPhoneLink.Uri, newPhone, Context).Result;
    if (result.Item1 == HttpStatusCode.OK || result.Item1 == HttpStatusCode.Created)
        return;
    else
        _logger.WarnFormat("ClientService.Post to {0} returned unexpected response code of: {1}", addPhoneLink.Uri, result.Item1);

    //C
    throw new Exception("Unable to process telephone number addition message");
}

The behaviour we observe is as follows - if one of A or C occurs, we inevitably get the message eventually delivered to the error queue, with the following information in the message extension:

<HeaderInfo>
    <Key>NServiceBus.ExceptionInfo.Message</Key>
    <Value>Unable to process change person name message</Value>
</HeaderInfo>
<HeaderInfo>
    <Key>NServiceBus.ExceptionInfo.Source</Key>
    <Value>ProjectName</Value>
</HeaderInfo>
<HeaderInfo>
    <Key>NServiceBus.ExceptionInfo.StackTrace</Key>
    <Value>System.Exception: Unable to process change person name message
    at ProjectName.Handlers.ChangePersonNameHandler.Handle(ChangePersonName message) in c:\TeamCity\buildAgent\work\6601b33332f54f3c\ProjectName\Handlers\ChangePersonNameHandler.cs:line 45
    at NServiceBus.Unicast.HandlerInvocationCache.Invoke(Object handler, Object message, Dictionary`2 dictionary) in c:\TeamCity\buildAgent\work\d4de8921a0aabf04\src\NServiceBus.Core\Unicast\HandlerInvocationCache.cs:line 63
    at NServiceBus.Unicast.UnicastBus.&lt;&gt;c__DisplayClass2f.&lt;DispatchMessageToHandlersBasedOnType&gt;b__2a(Action dispatch) in c:\TeamCity\buildAgent\work\d4de8921a0aabf04\src\NServiceBus.Core\Unicast\UnicastBus.cs:line 1093</Value>
</HeaderInfo>

(Apologies for switching to a different message type - I just wanted to find an example)

What seems to be consist, though, is that if the exception message matches the one given at point A, then the stack trace, and specifically this line:

at ProjectName.Handlers.ChangePersonNameHandler.Handle(ChangePersonName message) in c:\TeamCity\buildAgent\work\6601b33332f54f3c\ProjectName\Handlers\ChangePersonNameHandler.cs:line 45

Will invariably contain the line number for the exception at point C. And vice versa, if we get the exception message that should be produced at line C, then the stack trace's line number will finger the line A.

Any exception thrown by the methods inside section B seem to be faithfully reporting the correct line numbers. So it seems like exceptions directly thrown in the handler have this bizarre behaviour, but any exceptions throw by code we call into (e.g. from Linq if a sequence doesn't contain any elements) behaves as usual.

Aside from gibbering in disbelief, does anyone know of anything that can cause such a switch around to occur?

From packages.config:

  <package id="NServiceBus" version="4.0.1" targetFramework="net45" />
  <package id="NServiceBus.CastleWindsor" version="4.0.1" targetFramework="net45" />
  <package id="NServiceBus.Host" version="4.0.1" targetFramework="net45" />
  <package id="NServiceBus.Interfaces" version="4.0.1" targetFramework="net45" />
  <package id="NServiceBus.NHibernate" version="4.0.1" targetFramework="net45" />

Or is there any further investigating I should do, more info to add to the question, etc?

Angelesangelfish

Have you tried running the Handler outside of NServiceBus to see if the stacktrace is correct then? Does NServiceBus generate their own StackTrace information or do the they use the normal exception mechanism provided by .NET – Nicky

Try creating your own exception classes as well, ie TypeAException and TypeCException, then I'd guess the linenumber is wrong but the exception type is correct? – Galven

damien. this one sounds like fun. can u upload a repro somewhere? – Pachston

Please,show where the try catch block is. – Primipara

@Primipara - the catch block is inside NServiceBus code - I haven't delved into that code yet. – Angelesangelfish

Answer 1

1)

private void SomeMethod ( )
{
    try { //some code here }
    catch ( Exception е) 
    {
         throw е : / / CLR thinks that the exception line is there.
    }
}

2) it may be also caused by the C# compiler optimization try to add the attribute to your method to check it out:

 [Methodlmpl(MethodImplOptions.Noinlining)]

3) Are You using the hide implementation details exception pattern?

In my own opinion it is because Compiler optimization, because it can switch lines and optimize code a bit.

Primipara

Answer 2

I have experienced many weird behaviors when using Lambda expressions and Linq together. Both in run-time and in the editor (including frequent IDE crashes [machine independent]). So, I would rewrite section B without Linq and Lambda expressions.

Nonlegal