Funny Numbers In My Stack Trace

Tuesday, January 25, 2005

Someone in the newsgroups recently asked what the numbers mean in a release mode stack trace. For instance, what can you do with the following information?

[NullReferenceException: Object reference not set to an instance of an object.]
   aspnet.debugging.BadForm.Page_Load(Object sender, EventArgs e) +34
   System.Web.UI.Control.OnLoad(EventArgs e) +67
   System.Web.UI.Control.LoadRecursive() +35
   System.Web.UI.Page.ProcessRequestMain() +720

The stack trace gives us a little bit of information to go on, at least we can narrow the problem down to a specific method inside of a specific type, but +34 doesn’t seem to be particularly helpful – what does it mean? There are two answers to this question.

The first answer is: don’t worry about it. To narrow the source of the exception down to a single line of code, just build with debugging information (Project -> Properties -> Configuration Properties -> Build -> Generate Debugging Information). You should now have a PDB file output alongside your release mode assembly. With a PDB in place the runtime can give you a line number close to where the exception occurred.

 
[NullReferenceException: Object reference not set to an instance of an object.]
   aspnet.debugging.BadForm.Page_Load(Object sender, EventArgs e) in 
e:\dev\xprmnt\aspnet\debugging\badform.aspx.cs:16
   System.Web.UI.Control.OnLoad(EventArgs e) +67
   System.Web.UI.Control.LoadRecursive() +35
   System.Web.UI.Page.ProcessRequestMain() +720

The above answer is the practical answer, but it doesn’t satisfy the curious person who insists that all numbers have a meaning and a purpose. +34 isn’t some random number the runtime spits out after sampling the microphone input - so where does it come from?

For reference, the Page_Load method looks like the following:

using System;
using System.Web.UI;
using System.Web.UI.WebControls;
 
namespace aspnet.debugging
{
   public class BadForm : Page
   {
      protected Label Label1;
   
      private void Page_Load(object sender, EventArgs e)
      {         
         if(!IsPostBack)
         {
            string s = null;
            Label1.Text = s.Insert(0, "foo");
         }  
      }
 
      #region Web Form Designer generated code …
   }
}

We already know +34 doesn’t refer to a line of code. So perhaps the number refers to an offset into the IL instructions? Here is what ILDASM shows as the instructions for Page_Load.

.method private hidebysig instance 
void  Page_Load(object sender,
                class [mscorlib]System.EventArgs e) cil managed
{
  // Code size       34 (0x22)
  .maxstack  4
  .locals init ([0] string s)
  IL_0000:  ldarg.0
  IL_0001:  call       instance bool [System.Web]System.Web.UI.Page::get_IsPostBack()
  IL_0006:  brtrue.s   IL_0021
  IL_0008:  ldnull
  IL_0009:  stloc.0
  IL_000a:  ldarg.0
  IL_000b:  ldfld      class [System.Web]System.Web.UI.WebControls.Label aspnet.debugging.BadForm::Label1
  IL_0010:  ldloc.0
  IL_0011:  ldc.i4.0
  IL_0012:  ldstr      "foo"
  IL_0017:  callvirt   instance string [mscorlib]System.String::Insert(int32,
                                                                       string)
  IL_001c:  callvirt   instance void [System.Web]System.Web.UI.WebControls.Label::set_Text(string)
  IL_0021:  ret
} // end of method BadForm::Page_Load

No, 34 bytes puts us beyond the end of the IL instructions.

Let’s go one level lower into native code. Using WindDBG and SOS, it’s easy to view a disassembly of Page_Load after the JIT compiler has partied on the method. I use WinDBG to attach to the asp.net worker process after the page has executed and do a .load sos for managed debugging.

To view a disassembled method, you first need the address of the MethodDesc structure for the method, which name2ee can yield (aspnet.dll is the unfortunate name I gave my assembly):

!name2ee aspnet.dll aspnet.debugging.BadForm.Page_Load
--------------------------------------
MethodDesc: 1b873a0
Name: [DEFAULT] [hasThis] 
Void aspnet.debugging.BadForm.Page_Load(Object,Class System.EventArgs)

Now pass the address to the (u)nnassemble command.

!u 1b873a0
Normal JIT generated code
[DEFAULT] [hasThis] 
Void aspnet.debugging.BadForm.Page_Load(Object,Class System.EventArgs)
Begin 07f805b8, size 52
07f805b8 55               push    ebp
07f805b9 8bec             mov     ebp,esp
07f805bb 83ec10           sub     esp,0x10
07f805be 57               push    edi
07f805bf 56               push    esi
07f805c0 53               push    ebx
07f805c1 8955f8           mov     [ebp-0x8],edx
07f805c4 8bf1             mov     esi,ecx
07f805c6 33db             xor     ebx,ebx
07f805c8 8bce             mov     ecx,esi
07f805ca e819a8fef9       call    01f6ade8 (System.Web.UI.Page.get_IsPostBack)
07f805cf 0fb6f8           movzx   edi,al
07f805d2 85ff             test    edi,edi
07f805d4 752a             jnz     07f80600
07f805d6 33db             xor     ebx,ebx
07f805d8 8bbec4000000     mov     edi,[esi+0xc4]
07f805de ff357c40f906     push    dword ptr [06f9407c] ("foo")
07f805e4 8bcb             mov     ecx,ebx
07f805e6 33d2             xor     edx,edx
07f805e8 3909             cmp     [ecx],ecx
07f805ea ff1564ddb779  call dword ptr [mscorlib_79980000+0x1fdd64 (79b7dd64)]
                         (System.String.Insert)
07f805f0 8945f0           mov     [ebp-0x10],eax
07f805f3 8b55f0           mov     edx,[ebp-0x10]
07f805f6 8bcf             mov     ecx,edi
07f805f8 8b01             mov     eax,[ecx]
07f805fa ff9094010000     call    dword ptr [eax+0x194]
07f80600 90               nop
07f80601 5b               pop     ebx
07f80602 5e               pop     esi
07f80603 5f               pop     edi
07f80604 8be5             mov     esp,ebp
07f80606 5d               pop     ebp
07f80607 c20400           ret     0x4

The method starts at address 07f805b8. Moving 34 bytes into the method lands us on the ‘cmp [ecx], ecx’ instruction. CMP is an x86 opcode for compare, which seems like an odd thing to do until you realize the funny quirks of assembly language. For instance, earlier in the method you’ll see xor edx, edx. This instruction isn’t really trying to do an exclusive OR operation (XOR). Instead, this is an old trick used to set the EDX register to 0 in the fastest manner possible: by XORing the register against itself. The more obvious “mov edx, 0” (move 0 into edx) might cost an extra half nanosecond on a 3 GHz machine.

What the cmp instruction is doing here is carrying out part of the IL’s callvirt contract (referring to the IL you’ll see we do a callvirt to the String.Insert method). We can see in the dissasembly the next instruction calls the Insert method. callvirt is documented as throwing a NullReferenceExcecption if the object reference for the instance method you want to call is null. To make a long story a tad shorter: the ecx register contains the this pointer for the string instance that we want to call Insert on, and cmp [ecx], ecx generates a compact, 2 byte instruction to check ecx for null by dereferencing the ecx register. When the instruction dereferences the null pointer in ecx – program go boom.

In conclusion, +34 does have a meaning – it’s an offset into the native instructions for the method. Debugging at the assembly level doesn’t make any sense because you should always have PDBs available, but at least we can all sleep at night knowing the number 34 holds some meaning … somewhere.


Comments
John Tuesday, January 25, 2005
You are a total bad ass! But you knew that, right..? ;)
<br>
<br>Btw, how did you come to know what values are in the registers? How did you know that ecx holds the 'this' pointer? (Does something like line 8bce give that away? Or do you have a reference?)
<br>
<br>If you made the long story a tad shorter, then where's the long story!?
<br>
<br>(Do you know a good reference for x86 opcodes?)
<br>
<br>John.
Scott Wednesday, January 26, 2005
Yeah – I kinda got lazy towards the end because the post was feeling really long and I thought I was boring people to tears.
<br>
<br>The cmp instruction is one of those things I noticed that always appeared when there is a callvirt in IL. VB uses a call at times instead of a callvirt and the cmp doesn’t appear then. I remember one of Chris Brumme’s posts alluded to “one extra instruction” for a callvirt, but I can’t find the post now. It must have been phrased differently.
<br>
<br>WinDbg doesn’t label the columns here, but the first column is the address of the instruction, and the second column contains the code for the instruction, and then there is the instruction itself.
<br>
<br>This is a good book: http://webster.cs.ucr.edu/AoA/Windows/HTML/AoATOC.html. There are pdfs available for that on the net too.
<br>
<br>For reference manuals, Intel has tons of reference and optimization material: http://www.intel.com/design/pentium4/manuals/index_new.htm (see volume 2A and 2B).
<br>
Paul Thursday, February 24, 2005
I created an error handling page which sends out an email with error information.
<br>one of the things included in the email is
<br>exp.StackTrace.
<br>But in the email, I don't see any '+number'
<br>Do you know why?
<br>Is there a way to get the '+number'?
<br>
<br>eg.. if the error is
<br>[NullReferenceException: Object reference not set to an instance of an object.]
<br> aspnet.debugging.BadForm.Page_Load(Object sender, EventArgs e) +34
<br> System.Web.UI.Control.OnLoad(EventArgs e) +67
<br> System.Web.UI.Control.LoadRecursive() +35
<br> System.Web.UI.Page.ProcessRequestMain() +720
<br>
<br>in the email I get:
<br>
<br>[NullReferenceException: Object reference not set to an instance of an object.]
<br> aspnet.debugging.BadForm.Page_Load(Object sender, EventArgs e) at
<br> System.Web.UI.Control.OnLoad(EventArgs e) at
<br> System.Web.UI.Control.LoadRecursive() at
<br> System.Web.UI.Page.ProcessRequestMain()
<br>
<br>Thanks
Scott Friday, February 25, 2005
Have you tried with PDB files in place?
Comments are now closed.
by K. Scott Allen K.Scott Allen
My Pluralsight Courses
The Podcast!