locked
.NET decompile AND runtime error/debugging with async RRS feed

  • Question

  • User-745244032 posted

    This might (likely) be asked and answered elsewhere, but I can't get it straight in my head so last resort here might be helpful...

    its a three parter, but I think (at least in my mind) they are related... maybe... hopefully the examples below (although contrived) are accurate.

    Here goes:- given some code like this:

    var username = "bob";

    if I decompile it (ilspy, dnspy, etc):

    I sometimes get this:

    string <symbol> = "bob";
    others I get 
    string username = "bob";

    I think this has something to do with "runtime/debug" compilation (and perhaps generation of the .pdb file (although often I have this in both, but there must be SOMETHING that is "optimising away the variable names"... 

    Q (part 1): "why? whats the trick to this?"

    Secondly in an async await "scenario" 

    I have some code that throws this at runtime:

    Field not found: <BadlyWrittenCodeAsync>d__9.<>u__1

    I THOUGHT we could "get better debugging" than "d__9 and <>u__1" but "as per pt1" we couldn't figure out how to get these to "not be symbols"

    decompiling it shows a whole mess of thigns, but you are able to find "d__9" and "u__1" and they are (maybe)

    d__9 "TaskAwaiter<T>"
    u__1 "string" I think... the parameter to the async function...

    <not really part of the question but possibly relevant> when debugging this I think the problem was that the async call didn't have the string... in the function, but the caller did...>

    Q (part2): "how did this code compile and then fail at runtime?!"

    finally given the above made it very difficult to figure out what was wrong with the async await code... in the first place and that decompiling things didn't really make things much more obvious as to what was missing/wrong with the code...

    Q (part 3): "are there any tricks/improvements/techniques to debugging/logging better for async code, or if not, are there plans (eg future versions of .NET/csharp/other frameworks/tools) to improve this story?

    Sunday, February 14, 2021 2:26 AM

Answers

  • User753101303 posted

    Hi,

    Seems you have a  https://docs.microsoft.com/en-us/dotnet/api/system.missingfieldexception?view=net-5.0 exception? First make sure to look at ex.ToString() to get full details rather than just ex.Message (which iis perrhaps what you log now?) If I remember the async stack trace was improved in .NET Core 2.x. For now I never felt the need to decompile code.

    Further search gaves me https://github.com/benaadams/Ben.Demystifier which could also perhaps help..

    • Marked as answer by Anonymous Thursday, October 7, 2021 12:00 AM
    Sunday, February 14, 2021 10:58 PM
  • User-745244032 posted

    Hi PatriceSc- didnt' think about needing to mark as "partially  answered"...

    but YES you are right for #2 it compiled - the exception is only caught when the deserializer (im guessing, or the expandoObject) tried to get the strongly typed class to be populated from the "json" and one or more fields wasnt' there...

    I'm guessing that <>u__1 is some field (maybe the first?) of the generated object... or may be a total redherring... 
    that its trying to create from the JSON from the dynamic object... which wasn't even part of the THOUGHT of the async code!!! Just obscuring the thinking... which makes it KIND of related to the async questions #1 and #3 but only indirectly...

    (aside: yes we are getting the full error, I just posted the key bit because the rest of it doesn't shed any light AFAIK... ) 

    also: that demystifier, looks very cool... I will play with it now... but #2 is answered mostly thanks to this so thanks...

    PS: the "rest of the message"  in the exception details weren't included because (possibly due to the async thing) there are only two other "stack" elements:

    the function being called back to, and the exception
    at MyCode.BadCodeAsync(MyDTOStronglytypedThing x, string y)
    at SystemRuntime.CompilerServices.AsyncMethodBuilder....... TStateMachine...... System.MissingFieldException

    I don't think this is important, but perhaps it will help others if they find this question.

    I think this means that #1 and #3 are a little separate from #2 than I thought...

    and are still not answered...

    • Marked as answer by Anonymous Thursday, October 7, 2021 12:00 AM
    Monday, February 15, 2021 11:00 PM

All replies

  • User475983607 posted

    Q (part 3): "are there any tricks/improvements/techniques to debugging/logging better for async code, or if not, are there plans (eg future versions of .NET/csharp/other frameworks/tools) to improve this story?

    Logging is a much better debugging tool for asynchronous programming than using the Visual Studio debugger.  The debugger stops code execution which works great for synchronous code.  This stoppage makes debugging rather confusing because and asynchronous task can return at any time.  It is better to have a log that shows what happened in time.

    Sunday, February 14, 2021 3:12 PM
  • User-745244032 posted

    I agree, with this totally... and find the "as you go debug loggign" much more helpful, HOWEVER, in a cascading way (why I wrote this post with three related parts) "<BadCode>d__9.<>u__1>" in a log isn't very meaningful, unless you can decompile, AND you understand the obscure way that these symbols are patterned...? (plus this is "generated code class built by the "async await" csharp "thing"... so perhaps it will always be symbols (?) and never meaningful fieldnames...???)

    these are the kinds of things I'm trying to discover...

    is there even a pattern to this that can be gleaned?

    Sunday, February 14, 2021 10:35 PM
  • User753101303 posted

    Hi,

    Seems you have a  https://docs.microsoft.com/en-us/dotnet/api/system.missingfieldexception?view=net-5.0 exception? First make sure to look at ex.ToString() to get full details rather than just ex.Message (which iis perrhaps what you log now?) If I remember the async stack trace was improved in .NET Core 2.x. For now I never felt the need to decompile code.

    Further search gaves me https://github.com/benaadams/Ben.Demystifier which could also perhaps help..

    • Marked as answer by Anonymous Thursday, October 7, 2021 12:00 AM
    Sunday, February 14, 2021 10:58 PM
  • User475983607 posted

    I agree, with this totally... and find the "as you go debug loggign" much more helpful, HOWEVER, in a cascading way (why I wrote this post with three related parts) "<BadCode>d__9.<>u__1>" in a log isn't very meaningful, unless you can decompile, AND you understand the obscure way that these symbols are patterned...? (plus this is "generated code class built by the "async await" csharp "thing"... so perhaps it will always be symbols (?) and never meaningful fieldnames...???)

    these are the kinds of things I'm trying to discover...

    is there even a pattern to this that can be gleaned?

    You're making assumptions.  The build process generates intermediate code from high level C#.  The intermediate code is compiled into machine code at run-time

    You are trying to find meaning in code generation which is not intended for humans to read.  You'll need to read the build code to understand the how the intermediate code is generated.

    If you are asking how debuggers work, that's far beyond the scope of these forums.  

    Monday, February 15, 2021 12:03 PM
  • User-745244032 posted

    mgebhard

    I'm not making any assumptions at all, I'm asking a question - a complex one I'm guessing... but purely to get to a point where logged messages are actually more useful (for async code) at pointing to the offending class/function/field...

    Yes the FULL exception is being logged not just the "message" but this is no more (to me) helpful...

    I was literally asking the three related questions:

    1. what is/are the things that make "ILspy" (or whatever) show "#" (weird symbol) vs "reasonable variablename"
    2. how did this "code fail at runtime"  - which I think the answer to THIS bit is - that there was a typo in one of the response messages (from external service) as hinted at by the "field not found" reference (Missing field exception - PatriceSc)
    3. is there any way to improve the error message - eg: "WHICH FIELD" failed - parameter, dynamic data, etc... 

      my understanding of Exception messages in (all programming languages?) this case is that for speed/security or something else error messages often don't include details liek the data in fields at the exception... but wondering if this is (a) turn-on-able? or (b) somehow improvable in an application in some way that is sensible and maintainable?

    I thought this was a general asp.net question... but if you think it would be better placed elsewhere, then thats fine, please move it or suggest where to repost.

    Monday, February 15, 2021 10:46 PM
  • User-745244032 posted

    Hi PatriceSc- didnt' think about needing to mark as "partially  answered"...

    but YES you are right for #2 it compiled - the exception is only caught when the deserializer (im guessing, or the expandoObject) tried to get the strongly typed class to be populated from the "json" and one or more fields wasnt' there...

    I'm guessing that <>u__1 is some field (maybe the first?) of the generated object... or may be a total redherring... 
    that its trying to create from the JSON from the dynamic object... which wasn't even part of the THOUGHT of the async code!!! Just obscuring the thinking... which makes it KIND of related to the async questions #1 and #3 but only indirectly...

    (aside: yes we are getting the full error, I just posted the key bit because the rest of it doesn't shed any light AFAIK... ) 

    also: that demystifier, looks very cool... I will play with it now... but #2 is answered mostly thanks to this so thanks...

    PS: the "rest of the message"  in the exception details weren't included because (possibly due to the async thing) there are only two other "stack" elements:

    the function being called back to, and the exception
    at MyCode.BadCodeAsync(MyDTOStronglytypedThing x, string y)
    at SystemRuntime.CompilerServices.AsyncMethodBuilder....... TStateMachine...... System.MissingFieldException

    I don't think this is important, but perhaps it will help others if they find this question.

    I think this means that #1 and #3 are a little separate from #2 than I thought...

    and are still not answered...

    • Marked as answer by Anonymous Thursday, October 7, 2021 12:00 AM
    Monday, February 15, 2021 11:00 PM
  • User-745244032 posted

    Aside: From exploring the "Exception Details" watch window (for hours) its possible that "TargetSite" might contain more targeted information... if I could figure out #1... and make the symbol in "TargetSite.FullName/Name" or other field more meaningful...

    and so I'm back to #3...

    Monday, February 15, 2021 11:21 PM
  • User-745244032 posted

    no more?

    Thought or suggestions on where I might find information to help me understand the rest of this?

    eg:
    async "magical code" (eg: u<>1 -> Missing Field Exception) generated that then makes log/debug very hard to "interpret"?
    What/where to look to make this a better logged error, debug "tree" search experience?

    Sunday, February 28, 2021 6:47 AM
  • User753101303 posted

    From a quick try to create the same kind of error I see opmething such as:
    System.MissingFieldException: Field 'ConsoleApp6.Program+Test.a' not found. Don't you see this later part ?

    async/await generate code such as https://devblogs.microsoft.com/premier-developer/dissecting-the-async-methods-in-c/ which is perhaps what can make the call stack harder to understand but if you just ignore additional stack frames you should be able to see in which method it happens.

    I'll perhaps try in both. It was obscured in .NET 4.x but AFAIK .NET Core was changed to show a cleaner stack for async/await.

    Monday, March 1, 2021 1:25 PM