Getting started with windbg - part II
Update 2021: This is a re-post of a post from Johan Straarup - I am posting it here as his blog has been decommissioned
This is a continuation of my previous post with the imaginative name Getting started with windbg - part I. I’ll be assuming that you’ve read it, so if you haven’t I suggest you check it out first. We’re still working with the same sample dump, so I’ll pretty much pick up right where we left off.
More useful commands
Last time we used some nice commands from the sos-extension to look at the running call stacks, the requests, the CPU load of the threads, etc. We also dug deeper into the call stack to see what distinguished name we used for a SearchRequest. We’ll keep using these commands, but also learn a few new ones.
!dumpstackobjects (!dso)
Now, imagine that we’re looking at a specific thread and would like to see all managed objects referenced to by the current stack. Is there a way for us to do this? - There most certainly is. It’s called !dumpstackobjects, or !dso for short. If we run it on the current thread we’ll see a listing of objects that are referenced by the call stack. The whole output would look something like this (trimmed down to size):
0:050> !dso
OS Thread Id: 0x1e8c (50)
ESP/REG Object Name
17a9e534 0741f860 System.RuntimeType
17a9e6b8 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e6bc 27246f20 System.DirectoryServices.Protocols.SEC_WINNT_AUTH_IDENTITY_EX
17a9e740 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e744 27246f20 System.DirectoryServices.Protocols.SEC_WINNT_AUTH_IDENTITY_EX
17a9e764 27246f20 System.DirectoryServices.Protocols.SEC_WINNT_AUTH_IDENTITY_EX
17a9e768 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e780 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e784 27246e38 System.DirectoryServices.Protocols.SearchRequest
17a9e794 271fdf14 System.DirectoryServices.Protocols.LdapDirectoryIdentifier
17a9e7a8 27246ef8 System.Collections.ArrayList
17a9e7bc 27246ef8 System.Collections.ArrayList
17a9e7c8 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e8a4 27246e38 System.DirectoryServices.Protocols.SearchRequest
17a9e8d0 27246ed8 System.Object[] (System.Object[])
17a9e8e0 073ff6b8 System.String cn
17a9e8e4 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e8f4 27246d00 System.String CN=Dummy,CN=Accounts,CN=useradm,DC=Dummy,DC=net
17a9e8f8 271fdfe0 System.DirectoryServices.Protocols.LdapConnection
17a9e8fc 27246e38 System.DirectoryServices.Protocols.SearchRequest
17a9e910 03380310 System.String
17a9e914 27246e24 System.Object[] (System.String[])
17a9e918 272399a8 System.String CN=OID-Dummy-ABC123,CN=Dummy,CN=Accounts,CN=useradm,DC=Dummy,DC=net
17a9e91c 27246ddc System.String (CN=OID-Dummy-ABC123)
...
This is extremely useful when we want to see all the objects referenced by this thread alone. If you want to analyze one of the objects, simply copy the the address from the Object-column and use !dumpobject
0:050> !do 271fdfe0
Name: System.DirectoryServices.Protocols.LdapConnection
MethodTable: 14a2040c
EEClass: 149daf08
Size: 56(0x38) bytes
(C:\WINDOWS\assembly\GAC_MSIL\System.DirectoryServices.Protocols\2.0.0.0__b03f5f7f11d50a3a\System.DirectoryServices.Protocols.dll)
Fields:
MT Field Offset Type VT Attr Value Name
14a2078c 40000c3 4 ...NetworkCredential 0 instance 00000000 directoryCredential
14a2144c 40000c4 8 ...ificateCollection 0 instance 271fe018 certificatesCollection
1202af88 40000c5 10 System.TimeSpan 1 instance 271fdff0 connectionTimeOut
1466fe50 40000c6 c ...rectoryIdentifier 0 instance 271fdf14 directoryIdentifier
14a2034c 4000236 24 System.Int32 0 instance 2 connectionAuthType
14a223a4 4000237 18 ...dapSessionOptions 0 instance 271fe2d8 options
0fb896d8 4000238 28 System.IntPtr 0 instance 564180944 ldapHandle
120261c8 4000239 2c System.Boolean 0 instance 0 disposed
120261c8 400023a 2d System.Boolean 0 instance 0 bounded
120261c8 400023b 2e System.Boolean 0 instance 0 needRebind
14a22084 400023e 1c ...pResponseCallback 0 instance 271fe03c fd
120261c8 4000243 2f System.Boolean 0 instance 0 setFQDNDone
120261c8 4000244 30 System.Boolean 0 instance 1 automaticBind
120261c8 4000245 31 System.Boolean 0 instance 1 needDispose
120261c8 4000246 32 System.Boolean 0 instance 1 connected
14a2267c 4000247 20 ...s.QUERYCLIENTCERT 0 instance 271fe394 clientCertificateRoutine
0fd314bc 400023c 20 ...ections.Hashtable 0 shared static handleTable
>> Domain:Value 0019daf0:NotInit 11b42540:073fe504 <<
02c36ca0 400023d 24 System.Object 0 shared static objectLock
>> Domain:Value 0019daf0:NotInit 11b42540:073fe53c <<
0fd314bc 400023f 28 ...ections.Hashtable 0 shared static asyncResultTable
>> Domain:Value 0019daf0:NotInit 11b42540:073fe610 <<
14a21864 4000240 2c ...lResultsProcessor 0 shared static partialResultsProcessor
>> Domain:Value 0019daf0:NotInit 11b42540:073fe678 <<
12305e94 4000241 30 ....ManualResetEvent 0 shared static waitHandle
>> Domain:Value 0019daf0:NotInit 11b42540:073fe64c <<
14a21954 4000242 34 ...lResultsRetriever 0 shared static retriever
>> Domain:Value 0019daf0:NotInit 11b42540:073fe6a8 <<
!dumparray (!da)
As you might have noticed we have a couple of object arrays on the stack. Look for the System.Object[]-type in the listing above and you’ll find them. If you execute !dumpobject on an array you’ll only get information about the array itself, not it’s contents. To get information about what’s in the array we need to use the !dumparray-command, or !da for short.
0:050> !do 27239b98
Name: System.Object[]
MethodTable: 02c3896c
EEClass: 02c388ec
Size: 24(0x18) bytes
Array: Rank 1, Number of elements 2, Type CLASS
Element Type: System.String
Fields:
None
0:050> !da 27239b98
Name: System.String[]
MethodTable: 02c3896c
EEClass: 02c388ec
Size: 24(0x18) bytes
Array: Rank 1, Number of elements 2, Type CLASS
Element Methodtable: 02c39310
[0] 272399a8
[1] 27239a44
As you can see the !dumparray-command gives us a bit more information about the object. We can see that it contains System.String data and we get the addresses of the two items in the array. Since they’re System.String-objects we can simply use !dumpobject to view their contents.
!objsize
If you look at the listing above you’ll see that the size of the object is listed as 24 bytes. To paraphrase Obi Wan Kenobi: “This is true, from a certain point of view.” The 24 bytes are the size of the System.Object[]-object itself. Not it’s contents. As you can see when we execute !dumparray, the array only contains two references to two strings. These strings are individual objects and could be 32 MB for all we know, so the 24 bytes are not the total size of the array, but it would still be correct to claim that the System.Object[] is only 24 bytes large.
To get the total size of the object we use the !objsize command
0:050> !objsize 27239b98
sizeof(27239b98) = 348 ( 0x15c) bytes (System.Object[])
!objsize will iterate through all the child objects referenced by the object, as well as all the grandchildren and so on. Apparently the total size of the array and it’s child objects is 348 bytes.
If there are a lot of child objects it may take some time for !objsize to calculate the total size of the object. You should also be aware that !objsize may not always be as smart as you’d like. If, for example, you have a custom button control that references it’s parent aspx-page you’d get the total size of the aspx-page and all it’s child controls. In other words: If !objsize claims that the object in question is ridiculously large you might want to manually check what the object references using !dumpobject.
!dumpheap
This is another command that I use frequently. It is, however a command that you will want to use with at least one argument. !dumpheap with no arguments will dump all objects on the heap, so I usually begin by using the -stat argument, which in itself will write a lot of info on the screen, but it will at least be summarized. Here’ you’ll find the trimmed down output of !dumpheap -stat
0:050> !dumpheap -stat
------------------------------
Heap 0
total 2754508 objects
------------------------------
Heap 1
total 2761329 objects
------------------------------
total 5515837 objects
Statistics:
MT Count TotalSize Class Name
16e0a6d8 1 12 System.Collections.Generic.ObjectEqualityComparer`1[[System.Data.ProviderBase.DbConnectionInternal, System.Data]]
16d9cd9c 1 12 System.Xml.Serialization.Configuration.DateTimeSerializationSection+DateTimeSerializationMode
16d9bf30 1 12 System.Diagnostics.OrdinalCaseInsensitiveComparer
16d9112c 1 12 System.Xml.Serialization.NameTable
16d7f664 1 12 System.Xml.Serialization.TempAssemblyCache
163ea85c 1 12 System.Data.Res
1501e4c4 1 12 System.Collections.Generic.ObjectEqualityComparer`1[[System.Web.UI.Control, System.Web]]
14efb138 1 12 System.Net.TimeoutValidator
14ef9964 1 12 System.Net.Cache.HttpRequestCacheLevel
14ef77a8 1 12 Microsoft.Win32.WinInetCache
14ef68e4 1 12 System.Net.WebRequest+WebProxyWrapper
14ef658c 1 12 System.Net.Configuration.ProxyElement+BypassOnLocalValues
14ef63d8 1 12 System.Net.Configuration.ProxyElement+AutoDetectValues
14ef5b68 1 12 System.Net.CaseInsensitiveAscii
14ef5610 1 12 System.Net.HeaderInfoTable
14ef4718 1 12 System.Net.HttpRequestCreator
14db6710 1 12 System.Web.Configuration.MachineKeyValidationConverter
14db3140 1 12 System.Collections.Generic.ObjectEqualityComparer`1[[System.Runtime.Serialization.MemberHolder, mscorlib]]
14b3f4d8 1 12 System.Web.UI.SupportsEventValidationAttribute
...etc...
14a276a8 19578 704808 System.DirectoryServices.Interop.AdsValueHelper
14a2ea24 9196 735680 System.Web.UI.WebControls.Label
14a2e51c 16862 741928 System.Web.UI.WebControls.Style
125778ec 48015 768240 System.Collections.Specialized.NameObjectCollectionBase+NameObjectEntry
120261c8 65842 790104 System.Boolean
14a2ee7c 9198 809424 System.Web.UI.WebControls.Table
14b311c4 9647 810348 System.Web.UI.WebControls.Image
13a2b7dc 34913 837912 System.Web.HttpServerVarsCollectionEntry
14b303a4 10605 848400 System.Web.UI.WebControls.HyperLink
14d8e3d4 77748 932976 Microsoft.Web.UI.WebControls.BaseChildNodeCollection+ActionType
14db90ac 81372 976464 System.Web.UI.WebControls.FontInfo
14b30694 28648 1031328 System.Web.UI.WebControls.TableRow+CellControlCollection
14d8fdbc 38912 1089536 Microsoft.Web.UI.WebControls.TreeNodeCollection
14b3d0bc 86592 1385472 System.Web.UI.Pair
1466c5c4 39305 1414980 System.Web.UI.ControlCollection
14d8e48c 77748 1865952 Microsoft.Web.UI.WebControls.BaseChildNodeCollection+Action
1545061c 38874 2176944 Microsoft.Web.UI.WebControls.TreeNode
14b30eec 52668 2317392 System.Web.UI.WebControls.TableItemStyle
14a2f804 28515 2395260 System.Web.UI.WebControls.TableRow
14a2be6c 40894 2453640 System.Web.UI.LiteralControl
0fd3da00 228792 2745504 System.Int32
14b3e3ac 244793 2937516 System.Web.UI.IndexedString
14a2de94 198580 3177280 System.Web.UI.StateBag
1466c454 80512 3542528 System.Web.UI.Control+OccasionalFields
12302c2c 205849 4116980 System.Collections.Specialized.HybridDictionary
14b30024 52934 4446456 System.Web.UI.WebControls.TableCell
12302f2c 178294 4992232 System.Collections.Specialized.ListDictionary
14a2e284 412762 6604192 System.Web.UI.StateItem
14d8ce64 117078 7024680 Microsoft.Web.UI.WebControls.CssCollection
0fd314bc 132065 7395640 System.Collections.Hashtable
1230319c 422580 8451600 System.Collections.Specialized.ListDictionary+DictionaryNode
1202a58c 380438 9130512 System.Collections.ArrayList
0fd32050 133000 22582944 System.Collections.Hashtable+bucket[]
02c3896c 649842 23275900 System.Object[]
0fd3c12c 3471 36385536 System.Byte[]
001fee20 338 65409920 Free
02c39310 683083 161821000 System.String
Total 5515837 objects
Fragmented blocks larger than 0.5 MB:
Addr Size Followed by
2adf31cc 2.0MB 2aff85d8 System.String
2b006a2c 20.3MB 2c4530d8 System.Net.SocketAddress
As you can see we now get a listing sorted by size of all object-types on the heap. You’ll usually find strings down at the bottom since that’s what is commonly used the most.
Other useful arguments are -type and -mt (which stands for MethodTable). Using them you’re able to see all objects of a specific type. For example. If we want to look at all HttpRequestCreators on the heap (there are one) you’ll simply copy it’s MethodTable which you’ll find in the listing above (14ef4718) and use !dumpheap -mt
0:050> !dumpheap -mt 14ef4718
------------------------------
Heap 0
Address MT Size
0342ccf8 14ef4718 12
total 1 objects
------------------------------
Heap 1
Address MT Size
total 0 objects
------------------------------
total 1 objects
Statistics:
MT Count TotalSize Class Name
14ef4718 1 12 System.Net.HttpRequestCreator
This gives us the address of the object and if we’d like to inspect it closer we simply use !dumpobject on that address.
!dumpheap -type works pretty much the same way, except this time you filter the results by class name. !dumpheap -type performs a substring match, so if you write !dumpheap -type System.Web you’ll get every object who’s class name contains System.Web, which would be a lot.
Other useful arguments are -min and -max which accept a number representing the minimum/maximum number of bytes the object size should be. This can be really useful when troubleshooting string-abuse, etc. Also !dumpheap -stat -min 85000 would list all objects on the large object heap.
Putting the tools to use
I’d now like to use the commands we’ve covered in a bit more practical scenario. The dump we’ve been looking at is from a previous case of mine. The application in question was running on a Web garden with two worker processes. Session State was handled by a SQL Server. The customer was experiencing performance issues and the problem description was hazy at best. Anyway I had tons of dumps to work with, so I simply poked around to see what I could find. One thing I did pretty early on was to look at caching. According to the customer they weren’t using the cache at all, but I usually find it best to double-check this type of thing.
Determining the size of the cache
To find out how much data was kept in the cache I first needed to find the System.Web.Caching.Cache class. So I ran !dumpheap -stat -type System.Web.Caching.Cache. Note that I also used the -stat argument. Otherwise I would have gotten a very long list of System.Web.Caching.CacheKeys and System.Web.Caching.CacheEntrys as well. Anyway, here’s the result
0:050> !dumpheap -type System.Web.Caching.Cache -stat
------------------------------
Heap 0
total 665 objects
------------------------------
Heap 1
total 1084 objects
------------------------------
total 1749 objects
Statistics:
MT Count TotalSize Class Name
123056f8 1 12 System.Web.Caching.CacheKeyComparer
1230494c 1 12 System.Web.Caching.Cache
1230500c 1 24 System.Web.Caching.CacheMultiple
1230514c 1 32 System.Web.Caching.CacheMemoryStats
123053b4 1 36 System.Web.Caching.CacheMemoryTotalMemoryPressure
123059bc 2 40 System.Web.Caching.CacheUsage
12304bdc 1 48 System.Web.Caching.CacheCommon
123054f4 1 52 System.Web.Caching.CacheMemoryPrivateBytesPressure
12305874 2 64 System.Web.Caching.CacheExpires
12304e64 2 200 System.Web.Caching.CacheSingle
1255b594 85 1360 System.Web.Caching.CacheDependency+DepFileInfo
123046c4 40 1440 System.Web.Caching.CacheDependency
123042ec 47 1504 System.Web.Caching.CacheItemRemovedCallback
123063fc 832 16640 System.Web.Caching.CacheKey
12306820 732 52704 System.Web.Caching.CacheEntry
Total 1749 objects
Okay, so now I had the MethodTable for the System.Web.Caching.Cache object. Therefore I could now get the address to the object itself. I did this by asking !dumpheap to list all the objects on the heap with that MethodTable. I knew that there was just going to be one hit:
0:050> !dumpheap -mt 1230494c
------------------------------
Heap 0
Address MT Size
03392d20 1230494c 12
total 1 objects
------------------------------
Heap 1
Address MT Size
total 0 objects
------------------------------
total 1 objects
Statistics:
MT Count TotalSize Class Name
1230494c 1 12 System.Web.Caching.Cache
Total 1 objects
So now I ran !objsize on this object to see how big it was. This took a little time to calculate, since the cache is quite complex and there are a lot of children to iterate through.
0:050> !objsize 03392d20
sizeof(03392d20) = 266640828 ( 0xfe49dbc) bytes (System.Web.Caching.Cache)
So the cache is 266 MB in size. That’s quite a lot considering the fact that the customer claimed that they weren’t using the cache at all!
What is being cached?
To sample what the customer was caching I then took a look at a few of the CacheEntrys. I already had the MethodTable for the System.Web.Caching.CacheEntry from when I ran !dumpheap -type System.Web.Caching.Cache -stat (above), so I could use that to retrieve all CacheEntrys.
0:050> !dumpheap -mt 12306820
------------------------------
Heap 0
Address MT Size
033950bc 12306820 72
033a20d8 12306820 72
033ac79c 12306820 72
033da21c 12306820 72
033f04c4 12306820 72
03428ec8 12306820 72
0344dab4 12306820 72
03815d00 12306820 72
038265d8 12306820 72
....etc...
03af7010 12306820 72
03b291bc 12306820 72
03b2c674 12306820 72
03b6dca0 12306820 72
03b797dc 12306820 72
03b85318 12306820 72
03ba9150 12306820 72
03c258cc 12306820 72
03de43c8 12306820 72
03e160f8 12306820 72
total 382 objects
------------------------------
total 732 objects
Another valid command that would have given me the exact same output would off course have been !dumpheap -type System.Web.Caching.CacheEntry.
Okay, so now I had a long list of CacheEntrys. To sample the contents I just picked an address and examined it by using !dumpobject
0:050> !do 03b2c674
Name: System.Web.Caching.CacheEntry
MethodTable: 12306820
EEClass: 122f6470
Size: 72(0x48) 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
02c39310 4001327 4 System.String 0 instance 03b2c600 _key
0fb8f1f8 4001328 c System.Byte 0 instance 2 _bits
0fd3da00 4001329 8 System.Int32 0 instance -1314181915 _hashCode
02c36ca0 4001330 10 System.Object 0 instance 03b2c644 _value
120219d0 4001331 1c System.DateTime 1 instance 03b2c690 _utcCreated
120219d0 4001332 24 System.DateTime 1 instance 03b2c698 _utcExpires
1202af88 4001333 2c System.TimeSpan 1 instance 03b2c6a0 _slidingExpiration
0fb8f1f8 4001334 d System.Byte 0 instance 7 _expiresBucket
123062d8 4001335 34 ...g.ExpiresEntryRef 1 instance 03b2c6a8 _expiresEntryRef
0fb8f1f8 4001336 e System.Byte 0 instance 4294967295 _usageBucket
12306738 4001337 38 ...ing.UsageEntryRef 1 instance 03b2c6ac _usageEntryRef
120219d0 4001338 3c System.DateTime 1 instance 03b2c6b0 _utcLastUpdate
123046c4 4001339 14 ...g.CacheDependency 0 instance 00000000 _dependency
02c36ca0 400133a 18 System.Object 0 instance 033d8344 _onRemovedTargets
120219d0 400132d 1bc System.DateTime 1 shared static NoAbsoluteExpiration
>> Domain:Value 0019daf0:NotInit 11b42540:03395104 <<
1202af88 400132e 1c0 System.TimeSpan 1 shared static NoSlidingExpiration
>> Domain:Value 0019daf0:NotInit 11b42540:03395114 <<
1202af88 400132f 1c4 System.TimeSpan 1 shared static OneYear
>> Domain:Value 0019daf0:NotInit 11b42540:03395124 <<
This dumped the CacheEntry and it’s properties. I figured the most interesting piece of information would be the _value, so I simply copied the address of that property (look in the Value column) and used !dumpobject again.
0:000> !do 03e160c8
Name: System.Web.SessionState.InProcSessionState
MethodTable: 14dbad5c
EEClass: 14e43af8
Size: 48(0x30) 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
1466c9d8 4001d89 4 ...ateItemCollection 0 instance 1a7f5438 _sessionItems
1292672c 4001d8a 8 ...ObjectsCollection 0 instance 00000000 _staticObjects
0fd3da00 4001d8b c System.Int32 0 instance 20 _timeout
120261c8 4001d8c 18 System.Boolean 0 instance 0 _locked
120219d0 4001d8d 1c System.DateTime 1 instance 03e160e4 _utcLockDate
0fd3da00 4001d8e 10 System.Int32 0 instance 1 _lockCookie
1202bf60 4001d8f 24 ...ReadWriteSpinLock 1 instance 03e160ec _spinLock
0fd3da00 4001d90 14 System.Int32 0 instance 0 _flags
Here I found something interesting. The value stored was in fact an InProcSessionState object, which -in case you didn’t know this before- is stored in the Cache. This meant that the claim that the application was using SQL Server Session state was incorrect.
As it turned out the customer had temporarily switched to In-process for a brief test, but forgotten to switch back again. Had the application been live they would have spotted this in no time, but since they were stress testing they weren’t really paying attention to what the server was returning as long as it returned something. Unknowingly running session state in-process compromised the stress-test in a number of ways. For example:
- Memory usage for the worker process was a lot higher than expected
- The load on the network was not as high as it would be under normal circumstances
- The response times were no longer accountable
- The SQL-server was not stressed to the extent it should have been, so any potential bottlenecks there went unnoticed
This was in no way the final solution for their performance issue. There were a lot more things we had to deal with, but I think it’s a really nice example of how to use only three commands (!dumpheap, !objsize & !dumpobject) to dig up some really useful information.
Later! / Johan
