Digging Into Objects

One of our engineers asked me yesterday about getting the total size for objects in memory. The debugger is adept at doing such things, but you have to understand how object sizes are interpreted.

Let me start by giving you some background on how I'll typically deal with troubleshooting a high memory situation. The first thing of interest to me is whether we're dealing with a managed leak (.NET code) or a native leak. To discover that, I'll use the !eeheap debugger command.

0:000> !eeheap -gc
Loaded Son of Strike data table version 5 from "C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorsvr.dll"
Number of GC Heaps: 4
Large object heap starts at 0x232d0030
segment begin allocated size
0x232d0000 0x232d0030 0x23bdac68 0x0090ac38(9,481,272)
Heap Size 0x16980074(379,060,340)
------------------------------
GC Heap Size 0x575ef130(1,465,839,920)

I've edited out much of the output here for the sake of brevity, but you can clearly see that this output illustrates an enormous amount of memory being used by the managed heaps. (The -gc switch shows us what's in the GC heaps or managed heaps.) In this case, we're looking at over 1GB of memory in use. Based on that, I know that I need to dig into managed objects in order to locate the source of the problem.

In this post, I'm not going to dig into the particular dump I've shown above because it's an actual customer dump that I'm working on. Instead, I will show a simplified example based off of a simple example application. Don't worry. The concepts are actually more clearly illustrated from the example dump I will use.

 

What's using my memory?

Once you know that your memory is being sucked up by managed objects, you'll need to dig into the managed heaps to find out where your memory is being used. The first step in doing that is to dump out the heap statistics using !dumpheap -stat.

0:013> !dumpheap -stat
Loaded Son of Strike data table version 5 from "C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll"
total 108,014 objects
Statistics:
MT         Count  TotalSize  Class Name
0x79c025fc 1      12         System.UnloadWorker
0x79bfc98c 1      12         System.Runtime.Remoting.Activation.ActivationListener
0x79bfc7c4 1      12         System.Runtime.Remoting.Activation.LocalActivator
0x79bfc390 1      12         System.Reflection.DefaultMemberAttribute
0x79bf48ac 1      12         System.Runtime.Remoting.Messaging.IllogicalCallContext
0x033c7c24 10     200        Staticmethod.Sclass
0x00be209c 13,563 714,108    System.Object[]
0x79b925c8 21,893 2,659,728  System.String
0x00be2c3c 78     10,705,064 System.Byte[]
Total 108,014 objects, Total size: 16,259,364

This output shows you all of the objects in the managed heap ordered by the amount of memory used by that type. The first column you see is the address of the method table (MT) followed by the count of objects, the total size of all of the objects (which is what we'll dig into soon), and the class name. Naturally I have cut down the size of the output dramatically for this example, but what we need is displayed above.

In this example, it's clear that the majority of memory is taken up by System.Byte[], about 10MB. I'm interested in seeing where those byte arrays are coming from and the debugger will let you do that pretty easily using the !gcroot command. However, !gcroot works on the address of an object, and right now we only have the address of a method table. To find out the address of the objects within the method table, use !dumpheap with the -mt switch and pass it the method table address that you got from the !dumpheap -stat command.

0:013> !dumpheap -mt 0x00be2c3c
Address    MT         Size       Gen
0x00f02c54 0x00be2c3c 172        2       System.Byte[]
0x00f02efc 0x00be2c3c 12         2       System.Byte[]
0x00f062e8 0x00be2c3c 28         2       System.Byte[]
0x00f06438 0x00be2c3c 76         2       System.Byte[]
0x00f094a8 0x00be2c3c 172        2       System.Byte[]
0x00f09628 0x00be2c3c 172        2       System.Byte[]

. . . more output here . . .

0x01f0c020 0x00be2c3c 1,048,592  3       System.Byte[]
0x0200c030 0x00be2c3c 1,048,592  3       System.Byte[]
0x0210c050 0x00be2c3c 1,048,592  3       System.Byte[]
0x0220c070 0x00be2c3c 1,048,592  3       System.Byte[]
0x0230c090 0x00be2c3c 1,048,592  3       System.Byte[]
0x0240c0a0 0x00be2c3c 1,048,592  3       System.Byte[]
0x0250c0c0 0x00be2c3c 1,048,592  3       System.Byte[]
0x0260c0e0 0x00be2c3c 1,048,592  3       System.Byte[]
0x0270c100 0x00be2c3c 1,048,592  3       System.Byte[]
0x0280c120 0x00be2c3c 1,048,592  3       System.Byte[]
total 78 objects

You can clearly see a pattern here. Most of the memory from byte arrays is taken up by byte arrays that are almost exactly 1MB in size. (Notice also that this ouput shows you what generation an object is in. The large byte arrays are in the large object heap which is denoted here by gen 3.) In fact, many times when you have a memory issue, you will see patterns like this, but they are nowhere near as obvious as this. :)

Now that we have a better idea as to which byte arrays are the culprits, it's time to see what created them by using !gcroot on the address as I discussed above. We'll pick the first large one.

0:013> !gcroot 0x01f0c020
Scan Thread 1 (0x1720)
Scan Thread 5 (0x13f0)
Scan Thread 8 (0xff8)
Scan HandleTable 0x156aa0
Scan HandleTable 0x15a4b8
Scan HandleTable 0x235c68
HANDLE(Strong):44f1148:Root:0xf56500(System.Web.NativeFileChangeNotification)->
0xf564e4(System.Web.DirMonCompletion)->0xf56214(System.Web.DirectoryMonitor)->
0xf56318(System.Web.FileMonitor)->0xf56348(System.Collections.Hashtable)->
0xf5637c(System.Collections.Hashtable/bucket[])->0xf5467c(System.Web.FileChangesMonitor)->
0xf55da4(System.Web.FileChangeEventHandler)->0xf532d0(System.Web.HttpRuntime)->
0xf5496c(System.Web.Caching.CacheSingle)->0xf54a1c(System.Web.Caching.CacheExpires)->
0xf54c68(System.Object[])->0xf55728(System.Web.Caching.ExpiresBucket)->0x13700e8(System.Web.Caching.ExpiresEntry[])->
0x1370098(System.Web.Caching.CacheEntry)->0x1370068(System.Web.SessionState.InProcSessionState)->
0xfbfd38(System.Web.SessionState.SessionDictionary)->0xfbff80(System.Collections.Hashtable)->
0xfc924c(System.Collections.Hashtable/bucket[])->
0xfc0bdc(System.Collections.Specialized.NameObjectCollectionBase/NameObjectEntry)->
0xfc0b9c(Staticmethod.Sclass)->0x1f0c020(System.Byte[])

The !gcroot command walks the object tree and tells you where an object is rooted. (A discussion of this is outside of the scope of what I'm discussing here.) You can see that we scanned the threads as well as handletables. Each app domain had a handletable where objects can also be rooted. In this case, our byte array is rooted in a handletable and the output shows some interesting things worth discussing.

Let's look at this output starting at the CacheEntry object. You can see this byte array rooted in a CacheEntry object, then in InProcSessionState, and eventually, in a Staticmethod.Sclass object. What this tells us is that the Staticmethod.Sclass object is being stored in InProc Session state and that it is rooting the byte array. (In ASP.NET InProc Session state, objects are stored in cache which is why you see this rooted in a CacheEntry.)

Because of this ouput, I'm interested in having a look into the Staticmethod.Sclass object. If you refer back to the output of !dumpheap -stat, you'll see that there are 10 of these objects for a total of 200 bytes:

0x033c7c24 10 200 Staticmethod.Sclass

Let's use !dumpheap -mt to dump out these individual objects just as we did before.

0:013> !dumpheap -mt 0x033c7c24
Address    MT         Size Gen
0x00f0f164 0x033c7c24 20   2 Staticmethod.Sclass
0x00fc0b9c 0x033c7c24 20   2 Staticmethod.Sclass
0x00fc0c08 0x033c7c24 20   2 Staticmethod.Sclass
0x00fc0c48 0x033c7c24 20   2 Staticmethod.Sclass
0x00fc4230 0x033c7c24 20   2 Staticmethod.Sclass
0x00fc427c 0x033c7c24 20   1 Staticmethod.Sclass
0x00fc42bc 0x033c7c24 20   1 Staticmethod.Sclass
0x00fc42fc 0x033c7c24 20   1 Staticmethod.Sclass
0x00fc433c 0x033c7c24 20   1 Staticmethod.Sclass
0x00fc93a8 0x033c7c24 20   1 Staticmethod.Sclass
total 10 objects

Sure enough, there are 10 of these and each is 20 bytes for a total of 200 bytes. However, if you were to use the !objsize command to get the size of one of these objects, you might be surprised to see how large it actually is.

0:013> !objsize 0x00f0f164
sizeof(0xf0f164) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)

What the heck? Which one of these commands is giving me wrong information? Actually, neither. The output that you see from !dumpheap -mt shows you the size of ONLY the Staticmethod.Sclass object. It doesn't include the size of members of that class because those members are listed elsewhere in the output. Let's dig into this object size output a bit more.

You can get a good idea of what makes up the 1MB or so used by this object by simply using the -v switch for !objsize like so.

0:013> !objsize 0x00f0f164 -v
sizeof(0xf0f164) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc0bb0) = 32 ( 0x20) bytes (System.String)
sizeof(0x230c090) = 1,048,588 (0x10000c) bytes (System.Byte[])

Now things make a bit more sense. We can see from this ouput that the Staticmethod.Sclass object has a couple of member variables; a byte array that is 1,048,588 bytes and a string that's 32 bytes. Add the original 20 bytes to those two and you end up with 1,048,640, the value that !objsize returned. Pretty cool!

Note: It's worth noting that in normal circumstances, you would want to use a command like db to dump out these byte arrays and see what's in them. In this case, we're only interested in discussing the details of getting the size of objects, so I won't go into that in this post. Besides, I happen to know that there's nothing in these byte arrays. :)

Now for another cool trick. Suppose that you wanted to dump out the !objsize output for all of these. In this example, that's not too hard. After all, there are only 10 of them. However, suppose there were 3,000 of them. That would be quite an undertaking if you had to do it manually, but you don't have to. You can use the .foreach token in the debugger to do it for you! Check this out.

0:013> .foreach (obj {!dumpheap -mt 0x033c7c24 -short}) {!objsize obj}
sizeof(0xf0f164) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc0b9c) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc0c08) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc0c48) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc4230) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc427c) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc42bc) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc42fc) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc433c) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)
sizeof(0xfc93a8) = 1,048,640 (0x100040) bytes (Staticmethod.Sclass)

The format of this command is pretty simple. The "obj" is simply a variable that is populated by the output from the command in curly brackets immediately after it. In this case, I'm running !dumpheap -mt on the method table of the Staticmethod.Sclass objects. The -short switch causes the command to ONLY output the address of the object and no other details. Here's what that command outputs.

0:013> !dumpheap -mt 0x033c7c24 -short
0xf0f164
0xfc0b9c
0xfc0c08
0xfc0c48
0xfc4230
0xfc427c
0xfc42bc
0xfc42fc
0xfc433c
0xfc93a8

As you can see, this is the perfect kind of output if what we really want to do is loop through each one of these addresses and run a command on each. That's the purpose of the -short switch. I use it often, and now you see why.

The second set of curly brackets contains a second command to run on each "obj" variable, in this case, the !objsize command. The result is the size output of each object as you can see in the listing above.

Back to our theoretical example of 3,000 objects. You now know how to use the .foreach token to get the size of each, but you are still left with using a calculator to add them all up. Once again, the debugger comes to your rescue. You can use a feature of the debugger called "pseudo-registers" to store the cumulative size of objects and then output the total value once they've all been calculated. This allows you to actually add up the total values as you dump them. The command to do that is a bit trickier. Here it is.

0:013> r $t2 = 0; .foreach ( obj {!dumpheap -short -mt 0x033c7c24} ) { r $t2 = $t2 + 1; .foreach( theSize { !objsize -short obj } ) { r $t1 = $t1 + theSize; ? theSize } }; .echo Total Size:; ?$t1
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Evaluate expression: 1048640 = 00100040
Total Size:
Evaluate expression: 10486400 = 00a00280

This command uses the pseudo-registers I mentioned above to keep track of the objects. There are 20 pseudo-registers, $t0 - $t19. This command begins by assigning the value of 0 to the $t2 pseudo-register. (r $t2 = 0) After we assign that value, we loop through the objects as we did before. However, in this case, we keep track of the total size using a new variable (theSize). We increment the $t1 pseudo-register with each iteration. Finally, we print out the total size using the .echo command to print the value of the $t1 pseudo-register.

I realize that this may be getting a little confusing. Fortunately, the debugger comes with excellent documentation. I urge you to have a look. Pseudo-registers are a powerful feature of the debugger. The only drawback is that it may become tedious to remember these commands. In a future post, I'll show you how to set up aliases so that you can type a simple command and execute complex instructions that you've written. It's cool, I promise.

One more important thing to keep in mind. Getting the size of a complex object can take a long time, so you'll want to carefully decide whether or not you have the time for a command of this level of complexity to complete. I worked a case once where a customer had millions of a particular object. After running the debugger on it for over a day, I did some math and determined that it was going to take 36 years for the command to complete! The moral? Do your math first!

Happy debugging, and Merry Christmas!

Jim