Debugging Script: Dumping out current and recent ASP.NET Requests


When you debug asp.net applications it is often useful to find out which requests are currently executing, how long they have been executing, what the querystring was etc. Since getting this information from a dump can be a long and tedious process even if you know what you are doing, it lends itself extremely well for a script.


If you are only interested in the script itself, please skip to the last section, but if you’re anything like me, and want to know the nitty gritty details and want to look at some cool features in windbg (the script language and DML=Debugger Markup Language) you might just want to read the whole thing:)


Before we go into the script and its components I just want to mention that I am by no means an expert scripter so a lot of the code in my script could probably be written a lot better, but it does the job:)  feel free to optimize away and send in a new better version in the comments if you feel up to the task…


The second thing I want to mention, and this is always something that is a bit tricky with writing generic debugger scripts, is that I am working a lot with member variable offsets, and offsets change between versions so I will provide one script that works for 2.0.50727.42 and one that works for 2.0.50727.832 along with info on how I got the offsets, so if you get weird output, check your version and fix the offsets…


For the purposes of the disucssion I will use the .42 (RTM) offsets


Output and comments on output


The script basically displays info about all the HttpContexts/Requests that are currently on the heap. This means that it displays both requestst that are currently running and requests that have finished executing but have yet to be garbage collected.


The following fields are shown…

































Field Comment
HttpContext This is just a DML link to the System.Web.HttpContext object in case you need to look at one to get more details
StartTime The time ASP.NET got to the request, you can compare this to the Debug Session Time to figure out how long your request has been executing
Timeout Timeout in seconds, the default is 110 sec.  A value of 30000000 indicates that no timeout has been set, which in turn usually means that debug is set to true for this application.
HttpResponse A DML link to the System.Web.HttpResponse object in case you need to look at one to get more details
Completed Yes or No, if Completed is listed as No you will likely find the request executing on one of the threads. To find out which one you can !gcroot the HttpContext object
ReturnCode The HTTP Status code returned to the client
HttpRequest A DML link to the System.Web.HttpRequest object in case you need to look at one to get more details
RequestType POST or GET
URL+QueryString The URL and QueryString of the request

 



Finding the data


Each request that executes gets a HttpContext which in turn has a link to an ISAPIWorkerRequestInProcForIIS6, a HttpRequest and a HttpResponse. 


 


 

0:000> !do 02c3d7b8
Name: System.Web.HttpContext
MethodTable: 68a1bf04
EEClass: 68a1be94
Size: 152(0x98) bytes
GC Generation: 1
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name
..
68a1c204 4000f60 10 …m.Web.HttpRequest 0 instance 02c3d850 _request
68a1c4a4 4000f61 14 ….Web.HttpResponse 0 instance 02c3d900 _response

68a20574 4000f6c 38 …HttpWorkerRequest 0 instance 02c3d0cc _wr
..

From these 4 objects we can get to all the data we need…  Pay special attention to the Offset column, this is what we’ll use in the script.


The data we need from the different objects is…

0:000> !do 02c3d7b8
Name: System.Web.HttpContext
MethodTable: 68a1bf04
EEClass: 68a1be94
Size: 152(0x98) bytes
GC Generation: 1
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name

7910ca9c 4000f77 8c System.TimeSpan 1 instance 02c3d844 _timeout

0:000> !do 02c3d0cc
Name: System.Web.Hosting.ISAPIWorkerRequestInProcForIIS6
MethodTable: 68a1f7c8
EEClass: 68a1f748
Size: 252(0xfc) bytes
GC Generation: 1
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name
79105ef0 4001294 4 System.DateTime 1 instance 02c3d0d0 _startTime

0:000> !do 02c3d900
Name: System.Web.HttpResponse
MethodTable: 68a1c4a4
EEClass: 68a1c41c
Size: 184(0xb8) bytes
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name

79104f64 4001009 59 System.Boolean 0 instance 0 _completed

790fed1c 400100f 50 System.Int32 0 instance 200 _statusCode

0:000> !do 02c3d850
Name: System.Web.HttpRequest
MethodTable: 68a1c204
EEClass: 68a1c194
Size: 176(0xb0) bytes
GC Generation: 1
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name

68a5c230 4000fda 9c System.Int32 1 instance 2 _httpVerb

68a14528 4000fdc 14 …m.Web.VirtualPath 0 instance 02c3e870 _path

790fa3e0 4000fe2 28 System.String 0 instance 790d6584 _queryStringText


in summary…




































Field Location in relation to Context
Context Context
StartTime WebRequest+0x4=(Context+0x38)+0x4
TimeOut    Context+0x8C
Response Context+0x14
Completed Response+0x59=(Context+0x14)+0x59
ReturnCode Response+0x50=(Context+0x14)+0x50
Request Context+0x10
HttpVerb Request+0x9C=(Context+0x10)+0x9C
Path (Request+0x14)+0x8=((Context+0x10)+0x14)+0x8
QueryString Request+0x28=(Context+0x10)+0x28


 


Extracting the information we want


HttpContext Loop


First off we have to loop through the Contexts on the heap and we do that with the .foreach command.  The collection we are looping through is !dumpheap -type System.Web.HttpContext -short which gives us all the addresses to the HttpContexts

.foreach (hc {!dumpheap -type System.Web.HttpContext -short}){
$$ In here we can use ${hc} to get to the context object
$$ This is where all the printing will happen
}


With .foreach we split the output of whatever command we pass in on whitespaces and put the token into hc in this case.  After that we can use the notation ${alias} i.e. ${hc} to avoid that the debugger looks for a symbol to translate hc.


HttpContext with DML


I’m adding an exec DML link to turn the Context address into a link, and when you click it you will run !do <context address>

.printf /D “<?dml?><exec cmd=\”!do ${hc}\”>${hc}</exec>\t”;

If you want to know more about DML and what you can do with it you should check out the help file dml.doc in the debugging tools directory.


StartTime and TimeOut


If you look at…

Fields:
MT Field Offset Type VT Attr Value Name

7910ca9c 4000f77 8c System.TimeSpan 1 instance 02c3d844 _timeout

… you will notice that the VT column is set to 1, the same is true for the _startTime field.  Normally when you want to dump out a member variable you will do so by running !dumpobj <value>, and !dumpobj will look at the first DWORD for the MethodTable to figure out how to display it. 


ValueType member variables don’t have a header so if we want to dump this out we would have to use !dumpvc <methodtable> <address> to allow sos.dll to figure out how to display it.  The first column gives you the <methodtable> to use.

0:000> !dumpvc 7910ca9c 02c3d844
Name: System.TimeSpan
MethodTable 7910ca9c
EEClass: 7910ca24
Size: 16(0x10) bytes
(C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
Fields:
MT Field Offset Type VT Attr Value Name
790fcb80 4000525 0 System.Int64 1 instance 1100000000 _ticks
7910ca9c 4000522 118 System.TimeSpan 1 shared static Zero
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b31b28 <<
7910ca9c 4000523 11c System.TimeSpan 1 shared static MaxValue
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b31b38 <<
7910ca9c 4000524 120 System.TimeSpan 1 shared static MinValue
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b31b48 <<

We are interested in the _ticks value which is a UInt64 stored at offset 0, and we can get this by running dq <TimeSpan address> l1 which gives us 00000000`4190ab00 (the hex equivalent of 1100000000)

0:000> dq 02c3d844 l1
02c3d844 00000000`4190ab00

and then it is just a matter of parsing out the 2nd token of the result and divide this with decimal 10000000 to get a value in seconds since one tick is 100 ns.


Since I don’t know of a better way I am parsing with .foreach by taking the output and skipping the first token (/pS tells .foreach how many tokens to skip initially) and then I take that value and use it in the calculation to get the number of seconds…

0:001> ?00000000`4190ab00/0n10000000
Evaluate expression: 110 = 0000006e

And then finally parse with foreach again skipping the first two tokens to be able to print out the “110”… 


the code with some additional fluff to make the output look pretty looks like this…

.foreach /pS 1 /ps 99 (token {dq ${hc}+0x8c l1}){
.foreach /pS 2 /ps 99 (tk {?${token}/0n10000000}){
.if (${tk} > 9999){
.printf “${tk}\t\t”
}
.else {
.printf “${tk}\t\t\t”
}
}
};

To get the StartTime we can follow pretty much the same procedure with two important distinctions…


1. We need to remove the two most significant bytes of ticks/dateData before doing any conversions to time since these bytes contain info about the date format.  This is done by performing a bitwise and with 0x3FFFFFFFFFFFFFFF.


2. To convert it to Time we use formats and pull out token 22, 23 and 24 (Month, Day, Time)

0:000> !dumpvc 79105ef0 02c3d0d0
Name: System.DateTime
MethodTable 79105ef0
EEClass: 79105e50
Size: 16(0x10) bytes
(C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
Fields:
MT Field Offset Type VT Attr Value Name
79105638 40000f4 0 System.UInt64 1 instance 5244627895636415137 dateData
791240f0 40000f0 30 System.Int32[] 0 shared static DaysToMonth365
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b2f274 <<
791240f0 40000f1 34 System.Int32[] 0 shared static DaysToMonth366
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b2f2b4 <<
79105ef0 40000f2 28 System.DateTime 1 shared static MinValue
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b2f254 <<
79105ef0 40000f3 2c System.DateTime 1 shared static MaxValue
>> Domain:Value 001a8f88:NotInit 001cb1d8:02b2f264 <<

0:000> dq 02c3d0d0 l1
02c3d844 48c8a948`aa8352a1

0:001> ?(48c8a948`aa8352a1&0x3FFFFFFFFFFFFFFF)
Evaluate expression: 632941877209027233 = 08c8a948`aa8352a1

0:001> .formats 08c8a948`aa8352a1
Evaluate expression:
Hex: 08c8a948`aa8352a1
Decimal: 632941877209027233
Octal: 0043105224425240651241
Binary: 00001000 11001000 10101001 01001000 10101010 10000011 01010010 10100001
Chars: …H..R.
Time: Mon Sep 18 16:48:40.902 3606 (GMT+2)
Float: low -2.33276e-013 high 1.20769e-033
Double: 2.39006e-266


If you’re observant you will probably notice that it says that the request occurred in 3606:)  The real year in this case should have been 2006, but for some reason the time is always off by exactly 1600 years.  Anyways, just a curiosity, I’m not using the year anyways in the time output…


Another curiosity is that providing an initial skip to .foreach that is larger than 9 causes no tokens to be returned, so if you are wondering why there are so many nested .foreach statements to parse out the starttime, that is why… but again, I don’t really care about how pretty or ugly it looks as long as it works.


The code for the rest of the fields is pretty similar so I’ll leave it up to you to look at the code and figure out the rest.  The only thing I wanted to mention is the use of ad /q *…  this basically clears out all aliases so that you don’t get errors about redefined aliases if you run the script twice. 


Running the Scripts


To run the scripts just copy the code into a text file (dumpallexceptions.txt) and run it with $><c:\tools\extensions\DumpRequests.txt substituting the path for your own.


In order for the scripts to function you must first load sos.dll and preferably run a command like !threads or similar first to avoid any sos loading errors when running !dumpheap -type System.Web.HttpContext -short.


Modifying offsets


If the script doesn’t work and you are running differnet versions than the ones listed you can find the mt’s of Context, Response and Request in !dumpheap -stat and figure out what the offsets should be for your version.


Script 1: DumpAllRequsts.txt for 2.0.50727.42

$$
$$ Dumps all recent requests (all HttpContexts on heap)
$$
$$
$$ Written by: Tess
$$
$$ Run as: $><c:\tools\extensions\DumpRequests2.txt
$$
$$ For System.Web.dll 2.0.50727.42

$$ CLEAR ALL ALIASES (VARIABLES)
$$ ———————————————————————————-
ad /q *

$$ PRINT DUMP TIME FOR COMPARISON
$$ ———————————————————————————-
.time

$$ PRINT HEADER
$$ ———————————————————————————-
.printf “\nHttpContext\tStartTime\t\t\tTimeOut (sec)\tHttpResponse\tCompleted\tReturnCode\tHttpRequest\tRequestType”
.printf “\tURL+QueryString\n”
.printf “==========================================================================================================”
.printf “===============================”

$$ LOOP THROUGH ALL HTTP CONTEXTS THAT ARE STILL ON THE HEAP
$$ ———————————————————————————-
.foreach (hc {!dumpheap -type System.Web.HttpContext -short})
{
.printf “\n”;

$$ DISPLAY CONTEXT WITH DML LINK
$$ ———————————————————————————-
.printf /D “<?dml?><exec cmd=\”!do ${hc}\”>${hc}</exec>\t”;

$$ START TIME = CONTEXT->WR->_STARTTIME ((CONTEXT+0X38)+0X4)
$$ TICKCOUNT IS A QUADWORD AT THE START OF _STARTTIME, THE &0x3FFFFFFFFFFFFFFF IS USED TO REMOVE THE TWO FIRST BYTES
$$ (CALENDAR TYPE)
$$ .FOREACH COULD ONLY HANDLE AN INITIAL SKIP OF 9 THEREFORE I HAVE NESTED .FOREACH, SHOULD REALLY BE
$$ .FOREACH /PS 22, 23 AND 24
$$ ———————————————————————————-
.foreach /pS 1 /ps 99 (tick {dq poi(${hc}+0x38)+0x4 l1}){
.foreach /pS 3 /ps 99 (month {
.foreach /pS 9 (tk2 {
.foreach /pS 9 (tk {
.formats ${tick}&0x3FFFFFFFFFFFFFFF}){
.printf “${tk} “}}){
.printf “${tk2} “}}){
.printf “${month} “}
.foreach /pS 4 /ps 99 (day {
.foreach /pS 9 (tk2 {
.foreach /pS 9 (tk {
.formats ${tick}&0x3FFFFFFFFFFFFFFF}){
.printf “${tk} “}}){
.printf “${tk2} “}}){
.printf “${day} “}
.foreach /pS 5 /ps 99 (longtime {
.foreach /pS 9 (tk2 {
.foreach /pS 9 (tk {
.formats ${tick}&0x3FFFFFFFFFFFFFFF}){
.printf “${tk} “}}){
.printf “${tk2} “}}){
.printf “${longtime}\t”}
};

$$ TIMEOUT = CONTEXT->TIMEOUT (CONTEXT+0X8C) AND 1 TICK = 100 NS
$$ ———————————————————————————-
.foreach /pS 1 /ps 99 (token {dq ${hc}+0x8c l1}){
.foreach /pS 2 /ps 99 (tk {?${token}/0n10000000}){
.if (${tk} > 9999){
.printf “${tk}\t\t”
}
.else {
.printf “${tk}\t\t\t”
}
}
};

$$ DISPLAY RESPONSE WITH DML LINK (CONTEXT+0X14)
$$ ———————————————————————————-
.foreach /pS 4 (token {?poi(${hc}+0x14)}){
.printf /D “<?dml?><exec cmd=\”!do ${token}\”>${token}</exec>\t\t”
};

$$ COMPLETED = CONTEXT->RESPONSE->COMPLETED ((CONTEXT+0X14)+59)
$$ ———————————————————————————-
.foreach /pS 1 (token {dd poi(${hc}+0x14)+59 l1}){
.if (${token} == 0) {
.printf “No\t\t”
}
.else {
.printf “Yes\t\t”
}
};

$$ RETURNCODE = CONTEXT->RESPONSE->_STATUSCODE ((CONTEXT+0X14)+50)
$$ ———————————————————————————-
.foreach /pS 2 /ps 99 (token {?poi(poi(${hc}+0x14)+50)}){
.printf “${token}\t\t”
};

$$ DISPLAY REQUEST WITH DML LINK (CONTEXT+0X10)
$$ ———————————————————————————-
.foreach /pS 4 (token {?poi(${hc}+0x10)}){
.printf /D “<?dml?><exec cmd=\”!do ${token}\”>${token}</exec>\t”
};

$$ HTTPVERB = CONTEXT->REQUEST->_HTTPVERB ((CONTEXT+0X10)+9C)
$$ ———————————————————————————-
.foreach /pS 1 (token {dd poi(${hc}+0x10)+9C l1}){
.if (${token} == 2) {
.printf “GET\t\t”
}
.elsif (${token} == 5) {
.printf “POST\t\t”
}
.else {
.printf “Unparsed\t\t”
}
};

$$ PATH = CONTEXT->REQUEST->PATH->VIRTUALPATH (((CONTEXT+0X10)+14)+8)
$$ ———————————————————————————-
.foreach /pS 5 (tk {.foreach /pS 9 (token {!do -nofields poi(poi(poi(${hc}+0x10)+14)+8)}){.printf “${token} “}}) {
.printf “${tk}”
};

$$ QUERYSTRING = CONTEXT->REQUEST->QUERYSTRING ((CONTEXT+0X10)+28)
$$ ———————————————————————————-
.foreach /pS 5 (tk {.foreach /pS 9 (token {!do -nofields poi(poi(${hc}+0x10)+28)}){.printf “${token} “}}) {
.printf “?${tk}”
};
}


Script 2: DumpAllRequsts.txt for 2.0.50727.832

$$
$$ Dumps all recent requests (all HttpContexts on heap)
$$
$$
$$ Written by: Tess
$$
$$ Run as: $><c:\tools\extensions\DumpRequests.txt
$$
$$ For System.Web.dll 2.0.50727.832

$$ CLEAR ALL ALIASES (VARIABLES)
$$ ———————————————————————————-
ad /q *

$$ PRINT DUMP TIME FOR COMPARISON
$$ ———————————————————————————-
.time

$$ PRINT HEADER
$$ ———————————————————————————-
.printf “\nHttpContext\tStartTime\t\t\tTimeOut (sec)\tHttpResponse\tCompleted\tReturnCode\tHttpRequest\tRequestType”
.printf “\tURL+QueryString\n”
.printf “==========================================================================================================”
.printf “===============================”

$$ LOOP THROUGH ALL HTTP CONTEXTS THAT ARE STILL ON THE HEAP
$$ ———————————————————————————-
.foreach (hc {!dumpheap -type System.Web.HttpContext -short})
{
.printf “\n”;

$$ DISPLAY CONTEXT WITH DML LINK
$$ ———————————————————————————-
.printf /D “<?dml?><exec cmd=\”!do ${hc}\”>${hc}</exec>\t”;

$$ START TIME = CONTEXT->WR->_STARTTIME ((CONTEXT+0X38)+0X4)
$$ TICKCOUNT IS A QUADWORD AT THE START OF _STARTTIME, THE &0x3FFFFFFFFFFFFFFF IS USED TO REMOVE THE TWO FIRST BYTES
$$ (CALENDAR TYPE)
$$ .FOREACH COULD ONLY HANDLE AN INITIAL SKIP OF 9 THEREFORE I HAVE NESTED .FOREACH, SHOULD REALLY BE
$$ .FOREACH /PS 22, 23 AND 24
$$ ———————————————————————————-
.foreach /pS 1 /ps 99 (tick {dq poi(${hc}+0x38)+0x4 l1}){
.foreach /pS 3 /ps 99 (month {
.foreach /pS 9 (tk2 {
.foreach /pS 9 (tk {
.formats ${tick}&0x3FFFFFFFFFFFFFFF}){
.printf “${tk} “}}){
.printf “${tk2} “}}){
.printf “${month} “}
.foreach /pS 4 /ps 99 (day {
.foreach /pS 9 (tk2 {
.foreach /pS 9 (tk {
.formats ${tick}&0x3FFFFFFFFFFFFFFF}){
.printf “${tk} “}}){
.printf “${tk2} “}}){
.printf “${day} “}
.foreach /pS 5 /ps 99 (longtime {
.foreach /pS 9 (tk2 {
.foreach /pS 9 (tk {
.formats ${tick}&0x3FFFFFFFFFFFFFFF}){
.printf “${tk} “}}){
.printf “${tk2} “}}){
.printf “${longtime}\t”}
};

$$ TIMEOUT = CONTEXT->TIMEOUT (CONTEXT+0X9C) AND 1 TICK = 100 NS
$$ ———————————————————————————-
.foreach /pS 1 /ps 99 (token {dq ${hc}+0x9c l1}){
.foreach /pS 2 /ps 99 (tk {?${token}/0n10000000}){
.if (${tk} > 9999){
.printf “${tk}\t\t”
}
.else {
.printf “${tk}\t\t\t”
}
}
};

$$ DISPLAY RESPONSE WITH DML LINK (CONTEXT+0X14)
$$ ———————————————————————————-
.foreach /pS 4 (token {?poi(${hc}+0x14)}){
.printf /D “<?dml?><exec cmd=\”!do ${token}\”>${token}</exec>\t\t”
};

$$ COMPLETED = CONTEXT->RESPONSE->COMPLETED ((CONTEXT+0X14)+61)
$$ ———————————————————————————-
.foreach /pS 1 (token {dd poi(${hc}+0x14)+61 l1}){
.if (${token} == 0) {
.printf “No\t\t”
}
.else {
.printf “Yes\t\t”
}
};

$$ RETURNCODE = CONTEXT->RESPONSE->_STATUSCODE ((CONTEXT+0X14)+54)
$$ ———————————————————————————-
.foreach /pS 2 /ps 99 (token {?poi(poi(${hc}+0x14)+54)}){
.printf “${token}\t\t”
};

$$ DISPLAY REQUEST WITH DML LINK (CONTEXT+0X10)
$$ ———————————————————————————-
.foreach /pS 4 (token {?poi(${hc}+0x10)}){
.printf /D “<?dml?><exec cmd=\”!do ${token}\”>${token}</exec>\t”
};

$$ HTTPVERB = CONTEXT->REQUEST->_HTTPVERB ((CONTEXT+0X10)+98)
$$ ———————————————————————————-
.foreach /pS 1 (token {dd poi(${hc}+0x10)+98 l1}){
.if (${token} == 2) {
.printf “GET\t\t”
}
.elsif (${token} == 5) {
.printf “POST\t\t”
}
.else {
.printf “Unparsed\t\t”
}
};

$$ PATH = CONTEXT->REQUEST->PATH->VIRTUALPATH (((CONTEXT+0X10)+14)+8)
$$ ———————————————————————————-
.foreach /pS 5 (tk {.foreach /pS 9 (token {!do -nofields poi(poi(poi(${hc}+0x10)+14)+8)}){.printf “${token} “}}) {
.printf “${tk}”
};

$$ QUERYSTRING = CONTEXT->REQUEST->QUERYSTRING ((CONTEXT+0X10)+28)
$$ ———————————————————————————-
.foreach /pS 5 (tk {.foreach /pS 9 (token {!do -nofields poi(poi(${hc}+0x10)+28)}){.printf “${token} “}}) {
.printf “?${tk}”
};
}


Hopefully I didn’t mess up the scripts when I edited them for the post but if you get errors please post them and I’ll take a look at them as soon as possible. 


Also, if you happen to have some cool scripts laying around and want to share them please add them in the comments.  Anything that helps doing tedious work less tedious is really nice:)


Until next time,


Tess








Comments (22)

  1. LosManos says:

    hejdig.

    I would bet you 1600 comes from the conversion from julian to gregorian date system.  1600 is not the first gregorian year but something like the first leap year.

    See more about the gregorian calendar at:

    http://www.answers.com/topic/gregorian-calendar

    Search for Sweden for the history about when Sweden changed their calendar.  Marvellous lack of thinking.  And a headache for historians who get high on exact dates.

    Thanks for a really good blog.

    /OF

  2. Thiago says:

    Really helpful script!

    Thanks!

  3. Very nice script, Tess! :)

    Have you tried to use PowerShell?

    I’m using PowerShell to create WinDbg scripts. This approach has several benefits and opens endless possibilities.

  4. Tess says:

    Thanks for the links on the gregorian calendar… really interesting.  It appears that the reason it is 1600 years off probably has to do with exactly this… and that the CLR bases the ticks on 1/1 0001 (SYSTEM TIME) while WinDbg goes by FILETIME which is (ticks since 1/1 1601)

    http://blogs.msdn.com/oldnewthing/archive/2003/09/05/54806.aspx

    About PowerShell,

    I looked at it some time ago and I have written some scripts for it, but for things like this where a regular windbg script works well i feel that it is a bit of overkill using powershell… especially since you have to install powershell and do a bit of prework before you can use it…   For larger scripts I find it extremely interesting though…

  5. Brian says:

    Would it be possible to write a pre-processing script that could figure out the offsets rather than having them hardcoded?

  6. Tess says:

    Hi Brian,

    yes absolutely,

    you can run !name2ee System.Web.HttpContext and parse the output.

    I didn’t do it here because I wanted to do something that was fairly easy to write and read, plus the extra pre-processing would happen on every run of the script… I figured that typically when you debug your own servers you will stay at one version for a while.  

    If you happen to write a script with pre-processing, please post it though since I and I am sure a lot of people reading this would find it very interesting.

    Thanks

    Tess

  7. In my last post I wrote a script to dump out all the ASP.NET requests on the heap. Since one of the most

  8. Brian Hartung says:

    >> If you happen to write a script with pre-processing, please post it though since I and I am sure a lot of people reading this would find it very interesting.

    Well, since you asked…and considering all the help you’ve given us over the years, how could I turn down a request like that!  What an exercise in frustration learning the scripting language turned out to be.  But at least now I feel reasonably comfortable with it.

    It will be interesting to see what this code looks like since I’m posting it here in the Comments box…

    Cheers,

    -Brian

    $$

    $$ Title: GetOffsetsForDumpAllRequestsScript.txt

    $$

    $$ Description: Used to compute CLR version-specific offsets for ASP.NET

    $$ objects queried by the "DumpAllRequests" script written

    $$ by Tess Ferrandez (http://blogs.msdn.com/tess)

    $$

    $$ Author: If this script works, it was written by Brian Hartung (brian AT hartungconsulting DOT com)

    $$              If not, I don’t know who wrote it.

    $$

    $$ Run As: $><c:toolsextensionsComputeOffsetsForDumpAllRequestsScript.txt

    $$

    $$ License: Public domain.  Do with this script what you will (I won’t be offended).

    $$ Dump a CLR version header

    .block

    {

    .foreach /pS 0 (token {!eeversion})

    {

    .printf "$$ Auto-generated offsets for DumpAllRequests.txt scriptn"

    .printf "$$ CLR Version ${token}nn";

    .break

    }

    }

    $$ All of the following sections use the same basic pattern.  First an EEClass address

    $$ is computed for a class and stored in a user-defined property.  Next, the EEClass is

    $$ dumped and the output is scanned looking for a specific property name.  We make use

    $$ of the .shell directive and the standard Windows findstr.exe utility (which supports

    $$ searching using regular expresssions).  Although the use of .shell results in a good

    $$ deal of screen flicker, it’s quite a bit faster than iterating over the entire output

    $$ stream and tokenizing it using .foreach since it limits the results to the single row

    $$ we’re interested in.  This also has the benefit of being more resilient to CLR version

    $$ changes.  The sos.dll debugger extension could have breaking changes made to it, such as

    $$ adding a column to the right of the member name in !dumpclass or changing the column order

    $$ such that Offset is not the third column, but this seems less likely than new members being

    $$ added to a class (which would break any techniques that search for a known token name

    $$ and index from that to obtain the Offset value…this is because the offset column appears

    $$ earlier in the stream than the property name, so one (fragile) technique would be to search

    $$ for a token that’s expected to be at the end of the immediately preceding row and then index

    $$ forward from there.  The find.exe utility was not used because it will produce partial matches

    $$ and the algorithm here depends on an exact match on the property name.  As a final note, the

    $$ !dumpclass command was used rather than !dumpobject because 1) it doesn’t require having a

    $$ reference to a live object and 2) its output would also include value type members.

    $$ As a final note, the fact that the .shell directive caused all that annoying screen flashing

    $$ caused me to have the result of this script be the generation of a block of script that could

    $$ be pasted at the top of the DumpAllRequests script rather than having it run each time.  That

    $$ means each time a new version of the CLR is installed, this stub will have to be regenerated

    $$ and re-pasted.  If the screen flashing is less of a concern than having up-to-the-minute offset

    $$ values, then simply remove the .printf directives that surround the aS commands which would

    $$ cause them to be executed and stored in user-defined properties at runtime rather than simply

    $$ displayed for copying-and-pasting purposes.  Of course, anyone choosing to go that route will

    $$ hopefully not have a problem with photosensitive seizures.  Don’t say I didn’t warn you…

    $$

    $$ Compute required HttpContext member offsets

    $$

    .block {as gtCommand .shell -ci "!name2ee System.Web.dll System.Web.HttpContext" findstr /r ^EEClass:}

    .block

    {

    .foreach /pS 1 (token {${gtCommand}})

    {

    .block {aS HttpContextEEClass 0x${token}}

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${HttpContextEEClass}" findstr /r _timeout$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS HttpContextTimeoutOffset 0x${token}}n"

    .break

    }

    }

    $$

    $$ Compute required ISAPIWorkerRequest member offsets

    $$

    .block {as gtCommand .shell -ci "!name2ee System.Web.dll System.Web.Hosting.ISAPIWorkerRequestInProcForIIS6" findstr /r ^EEClass:}

    .block

    {

    .foreach /pS 1 (token {${gtCommand}})

    {

    .block {aS ISAPIWorkerRequestEEClass 0x${token}}

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${ISAPIWorkerRequestEEClass}" findstr /r _startTime$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS ISAPIWorkerRequestStartTimeOffset 0x${token}}n"

    .break

    }

    }

    $$

    $$ Compute required HttpResponse member offsets

    $$

    .block {as gtCommand .shell -ci "!name2ee System.Web.dll System.Web.HttpResponse" findstr /r ^EEClass:}

    .block

    {

    .foreach /pS 1 (token {${gtCommand}})

    {

    .block {aS HttpResponseEEClass 0x${token}}

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${HttpResponseEEClass}" findstr /r _completed$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS HttpResponseCompletedOffset 0x${token}}n"

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${HttpResponseEEClass}" findstr /r _statusCode$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS HttpResponseStatusCodeOffset 0x${token}}n"

    .break

    }

    }

    $$

    $$ Compute required HttpRequest member offsets

    $$

    .block {as gtCommand .shell -ci "!name2ee System.Web.dll System.Web.HttpRequest" findstr /r ^EEClass:}

    .block

    {

    .foreach /pS 1 (token {${gtCommand}})

    {

    .block {aS HttpRequestEEClass 0x${token}}

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${HttpRequestEEClass}" findstr /r _httpVerb$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS HttpRequestHttpVerbOffset 0x${token}}n"

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${HttpRequestEEClass}" findstr /r _path$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS HttpRequestPathOffset 0x${token}}n"

    .break

    }

    }

    .block {as gtCommand .shell -ci "!dumpclass ${HttpRequestEEClass}" findstr /r _queryStringText$}

    .block

    {

    .foreach /pS 2 (token {${gtCommand}})

    {

    .printf ".block {aS HttpRequestQueryStringTextOffset 0x${token}}n"

    .break

    }

    }

    $$ Clear out the user-defined aliases so we don’t leave garbage lying around

    ad /q *

  9. Tess says:

    Awesome stuff… thank you much for posting it Brian

  10. I created another WinDbg script which hopefully you might find useful.  The idea is that when you run a command and parse the output tokens using the .foreach command, it’s not always possible to index into the stream using a fixed offset, but rather it might be useful to search for a known value and then index a fixed number of tokens from there.  I created a script called GetToken for just such a purpose.  Because scripts don’t seem to post too well in these Comments (extra line breaks, loss of indentation, etc.), I have also posted a copy on my blog (http://brianhartung.blogspot.com/2007/09/useful-windbg-script-gettoken.html) which should retain all the formatting.

    Instructions for usage, parameters and outputs are embedded in the comments.

    Hope you find this useful,

    -Brian

    $$

    $$ GetToken: A helper function used to run a specified command, search for a

    $$ specified token value in the output stream from the command and

    $$ then return the nth token following that specified search value

    $$ in a specified alias name.

    $$

    $$ Returns: 1) The value of the nth token in the specified alias

    $$ 2) A status code in $t0 (0 = Token Not Found / 1 = Token Found)

    $$ 3) The offset to the specified search token in $t1

    $$

    $$ Written by: If this code works, it was written by Brian Hartung.  If not, I

    $$ don’t know who wrote it.

    $$

    $$ Run As: $$>a< c:toolsextensionsGetToken.txt "CommandToRun" "SearchValue" 0xn ReturnAlias

    $$

    $$ Example: To return the address of the EEClass for HttpContext, use these parameters:

    $$

    $$ "!name2ee System.Web.dll System.Web.HttpContext" "EEClass:" 1 HttpContextEEClass

    $$

    $$ Notes: 1) the value for parameter n must be specified in hex

    $$ 2) the last two parameters must not have quotes

    $$ 3) the alias name specified for returning the value must not already be defined

    $$

    $$ License: Public Domain.  Do with this script what you will (I won’t be offended).

    $$

    $$ Reset $t0 which will be used to return a success (1) or failure (0) status code

    r $t0=0

    $$ Reset $t1 which will be used as a token counter

    r $t1=0

    $$ Loop through the tokens returned by the command supplied in arg1

    .foreach (token {$arg1})

    {

    $$ The string comparison function $scmp returns 0 if the strings match.

    $$ In this case, we’re looking to see if the current token matches the

    $$ search value supplied in arg2

    .if($scmp("${token}", "$arg2")==0)

    {

    $$ Compute the total offset to the desired token, which is the

    $$ index of the search token plus the number of tokens to skip

    $$ as specified in arg3

    .block {r $t1 = @$t1 + ${$arg3}}

    $$ Skip directly to the desired token

    .foreach /pS $t1 (returnValue {$arg1})

    {

    $$ Store the current token in the specified return value alias

    .block {aS ${$arg4} ${returnValue}}

    $$ No need to consider any more tokens

    .break

    }

    $$ Return the success status code

    r $t0 = 1

    .break

    }

    .else

    {

    $$ Haven’t found it yet, so keep incrementing the counter until we do

    r $t1 = $t1 + 1

    }

    }

  11. Tess says:

    Again, really cool…  thank you very much for posting these Brian,  this latest one will be really useful…

  12. Vishwas says:

    awesome post!!

    for the boolean values – it looks like only the last bit is counted for whether the value is true or false. So for Completed status,

    .foreach /pS 1 (token {dd poi(${hc}+0x14)+61 l1}){

    .if (${token} == 0) {

    .printf "Nott"

    }

    .else {

    .printf "Yestt"

    }

    };

    will say completed even if the vlaue at that address is 00000100, which is false or the request is incomplete.

    Instead what worked for me was –

           .if ($spat("${token}", "???????1")){

               .printf "Yesn"

           }

           .else{

               .printf "Non"

           }

    Do correct me if I am wrong, since I am a newbie to windbg and whatever I have learnt about scripts for windbg is from this post :).

  13. Tess says:

    great,  yeah the scripts are a bit quick and dirty so i’m not surprised if there are issues with them on different versions.

    THanks for the correction

  14. Lately, no matter where you turn there is LINQ presentations and Silverlight demos. A couple of years

  15. Tess says:

    I wrote in the blog post "Another curiosity is that providing an initial skip to .foreach that is larger than 9 causes no tokens to be returned"  and I just got a note from Dan Wilson explaining this curiosity to me… apparently the value you give for the initial skip is hexadecimal (rather than decimal like i thought), so initial skips over 9 work just fine, its just a matter of giving the value in hex instead of decimal…

    Thanks much Dan for that insight, makes it a lot easier to write scripts since you dont have to nest the .foreach loops

  16. rox19840702 says:

    September 16th Links: ASP.NET, ASP.NET AJAX, IIS7, Visual Studio, Silverlight

  17. This question that I got from a reader is something that I get asked pretty frequently… "I met a small

  18. Kumar says:

    Hi Tess

    Just wondering if adding this pre condition to the scripts above would ensure that only "HttpContext" objects are processed as !dumpheap can potentially return all types which have HttpContext in their name like HttpContextWrapper

    $$ FIND THE MT Address for HttpContext

    r @$t0=0;

    .foreach /pS 6 /ps 100 (tokenMT {!name2ee System.Web.dll System.Web.HttpContext})

    {

    r$t0 = ${tokenMT};

    };

    $$ LOOP THROUGH ALL HTTP CONTEXTS THAT ARE STILL ON THE HEAP

    $$ ———————————————————————————-

    .foreach (hc {!dumpheap -mt @$t0 -short})

    {

    }

    Also I’m curious why virtual path extraction is done using nested .foreach as

    .foreach /pS 2 (tk {.foreach /pS 9 (token {!do -nofields poi(poi(poi(${hc}+0x10)+14)+8)}){.printf "${token} "}}) {

    .printf "${tk}"

    };

    instead of

    .foreach /pS 11 (token {!do -nofields 025c0384}){.printf "${token} n"}

    Am I missing something here?

    Many thanks

  19. PBSurfRider says:

    Can someone please explain how to run this script?  I installed WinDbg and saved the script to a txt file.  Now what?  There’s no command line entry anywhere…

  20. Tess says:

    You would have to attach to an asp.net process (w3wp.exe) or open a dump of a w3wp.exe process and then run the script from the windbg commandline (the command prompt at the bottom of windbg) like this

    $><c:toolsDumpRequests.txt

    Replacing the path with your own path

  21. Kevin Goff says:

    Very helpful.  Too bad !aspxpages isnt available for 2.x.  Will try and adapt this to the version I’m running.

  22. Nagendra says:

    How can we get the same request in .net 4.5? I am not able to get the start time or completed time. I have followed the same steps as described below.