If broken it is, fix it you should

Using the powers of the debugger to solve the problems of the world - and a bag of chips    by Tess Ferrandez, ASP.NET Escalation Engineer (Microsoft)

ASP.NET Case Study: Bad perf, high memory usage and high CPU in GC - Death By ViewState

ASP.NET Case Study: Bad perf, high memory usage and high CPU in GC - Death By ViewState

Rate This
  • Comments 22

I get enough issues relating to bad perf caused by large viewstate that I felt like it is time to dedicate some blog space to it, so here is a typical problem description for this type of problem.

Problem description:

Under high load the ASP.NET application will completely go down and stop serving pages, at the same time we can see in perfmon that the ASP.NET process is hogging the CPU and that memory (process\private bytes and .NET CLR Memory\#bytes in all heaps) also seems to keep rising for the ASP.NET process.

First thoughts:

With issues that are both memory and CPU related, my first inclination is to look at ".NET CLR Memory\% Time in GC" and ".NET CLR Memory\Allocated Bytes/sec" to see if the issue is that we have a very high allocation rate leading to high CPU in GC.  Additionally the ratio between #Gen 0, Gen 1 and Gen 2 Collections is interesting as well as .NET CLR Memory\Large Object Heap Size, since most of these issues tend to relate around allocating a lot of memory on the large object heap, incurring a lot of full Garbage Collections.

See my previous post on High CPU in GC for more details.

If we do that in this case we will see that indeed allocation rates are very high, 6-10 MB/sec and the ratio between Gen 2 and Gen 1 collections are pretty much 1:1.   

Debugging the issue:

We can take a memory dump with adplus -hang w3wp.exe when the CPU is really high, so I started with that and this is what I found.

The first thing I'm looking for when debugging these is what active .NET threads we have (using ~* e !clrstack)

OS Thread Id: 0x8b8 (13)
ESP EIP
0219f298 7d61c824 [HelperMethodFrame: 0219f298]
0219f304 66008731 System.Web.HttpUtility+UrlDecoder.AddByte(Byte)
0219f310 660081ee System.Web.HttpUtility.UrlDecodeStringFromBytesInternal(Byte[], Int32, Int32, System.Text.Encoding)
0219f344 660077a7 System.Web.HttpUtility.UrlDecode(Byte[], Int32, Int32, System.Text.Encoding)
0219f358 6600a08a System.Web.HttpValueCollection.FillFromEncodedBytes(Byte[], System.Text.Encoding)
0219f37c 65ff83df System.Web.HttpRequest.FillInFormCollection()
0219f3b4 65ffb226 System.Web.HttpRequest.get_Form()
0219f3c0 65ffb2a6 System.Web.HttpRequest.get_HasForm()
0219f3c8 66326b52 System.Web.UI.Page.GetCollectionBasedOnMethod(Boolean)
0219f3d4 6613854d System.Web.UI.Page.DeterminePostBackMode()
0219f3f8 6613d076 System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)
0219f5b0 6613cd41 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)
0219f5e0 6613cca7 System.Web.UI.Page.ProcessRequest()
0219f618 6613cbc7 System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)
0219f620 6613cb5a System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)
0219f634 0ef00125 ASP.allthepeople_aspx.ProcessRequest(System.Web.HttpContext)
0219f638 65fe90df System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
0219f66c 65fba191 System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
0219f6ac 65fba4bb System.Web.HttpApplication.ResumeSteps(System.Exception)
0219f6f4 65fb924d System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)
0219f710 65fbe244 System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)
0219f744 65fbde92 System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)
0219f750 65fbc567 System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
0219f900 79f2d0f3 [ContextTransitionFrame: 0219f900]
0219f950 79f2d0f3 [GCFrame: 0219f950]
0219faa8 79f2d0f3 [ComMethodFrame: 0219faa8]

 

... and if we look at the native part of this particular thread with kb we find:

13 Id: 1630.8b8 Suspend: 1 Teb: fff88000 Unfrozen
ChildEBP RetAddr Args to Child
0219ef68 7d4d8c56 000002f4 00000000 00000000 ntdll!ZwWaitForSingleObject+0x15
0219efd8 79e87d19 000002f4 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xac
0219f01c 79e87ce2 000002f4 ffffffff 00000000 mscorwks!PEImage::LoadImage+0x199
0219f06c 79e87c98 ffffffff 00000000 00000000 mscorwks!CLREvent::WaitEx+0x117
0219f07c 79f5c7cd ffffffff 00000000 00000000 mscorwks!CLREvent::Wait+0x17
0219f0a0 79f5c6d0 ffffffff 001a5718 0219f194 mscorwks!SVR::gc_heap::wait_for_gc_done+0x99
0219f0c4 79f5c4a1 00000000 00000000 000cb618 mscorwks!SVR::GCHeap::GarbageCollectGeneration+0x267
0219f154 79f50f95 0219f194 000cb618 00000003 mscorwks!SVR::gc_heap::try_allocate_more_space+0x1bc
0219f174 79f54a70 0219f194 000cb618 00000003 mscorwks!SVR::gc_heap::allocate_more_space+0x2f
0219f1b0 7a0e7c4a 000cb612 00000000 00000000 mscorwks!SVR::gc_heap::allocate_large_object+0x86
0219f1cc 79e84c69 001b0b88 000cb612 00000000 mscorwks!SVR::GCHeap::Alloc+0xbc
0219f1e8 79e8e3a1 000cb612 00000000 00000000 mscorwks!Alloc+0x60
0219f23c 79e8e401 791244f4 000cb606 00000000 mscorwks!FastAllocatePrimitiveArray+0xbd
*** WARNING: Unable to verify checksum for System.Web.ni.dll
0219f2fc 66008731 00000002 0b4063d0 660081ee mscorwks!JIT_NewArr1+0x148
0219f308 660081ee 0000000c 0000002f 00000001 System_Web_ni+0xe8731
0219f334 660077a7 02b27338 000cb606 000dff7f System_Web_ni+0xe81ee
0219f348 6600a08a 02b27338 000cb606 033c98ac System_Web_ni+0xe77a7
0219f370 65ff83df 02b27338 41300000 00000000 System_Web_ni+0xea08a
*** WARNING: Unable to verify checksum for System.ni.dll
0219f38c 7a4a995b 00000000 033c6d34 033c98ac System_Web_ni+0xd83df
0219f3ac 65ffb226 033c6dcc 00000000 65ffb2a6 System_ni+0x6995b

 

So this thread is in the middle of executing a HTTP request (aspx page) and more specifically it is filling in the forms collection, and during this call it needs to make an allocation.  From the native stack we can see that we are allocating a large object (0xcb612 bytes in size), and that this triggers a garbage collection.

 

If we examine this thread a little bit further by looking at the objects on the stack (!dso) we will find a few interesting objects:

0:013> !dso
OS Thread Id: 0x8b8 (13)
ESP/REG Object Name
0219f120 0b4063d0 System.Byte[]
0219f1a0 0b4e6370 System.Char[]
...
0219f35c 033fb3e4 System.String __VIEWSTATE
...
0219f3b4 033c6dcc System.Web.HttpRequest
...
0219f3c8 033c7674 ASP.allthepeople_aspx
...

First off, we can see that the page we are executing on this thread is called AllThePeople.aspx and that the forms element we are looking at is __VIEWSTATE.

If we examine the HttpRequest we will notice that the _contentLength is 917375 indicating that it is a pretty large page, and we can see that we don't have a querystring (the reson I still show the querystring is that is good to have this data for repro purposes).

0:013> !do 033c6dcc
Name: System.Web.HttpRequest
MethodTable: 6637e1c0
EEClass: 6637e150
Size: 172(0xac) 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
...
790fa4c8 4000fe9 28 System.String 0 instance 00000000 _queryStringText
...
790fee08 4000fee 9c System.Int32 0 instance 917375 _contentLength
...

And if we dump out the byte array at the top of the stack we find

0:013> dc 0b4063d0
0b4063d0 791244f4 000dff7f 49565f5f 54535745 .D.y....__VIEWST
0b4063e0 3d455441 77463225 77445045 6a4d4b55 ATE=%2FwEPDwUKMj
0b4063f0 7a4e7841 544f3041 674d3363 67466b39 AxNzA0OTc3Mg9kFg
0b406400 77414349 67466b39 51414349 78445138 ICAw9kFgICAQ8QDx
0b406410 67484359 55496674 47646852 33624346 YCHgtfIURhdGFCb3
0b406420 475a7556 42456b64 6a544f57 5751444a VuZGdkEBWOTjJDQW
0b406430 575a6738 325a7356 53597335 32627042 8gZWVsZ25sYSBpb2
0b406440 6d62346b 44493074 434e7052 79617042 k4bmt0IDRpNCBpay
0:013> d
0b406450 47627235 6d525631 575a6868 3263504e 5rbG1VRmhhZWNPc2
0b406460 57647378 45627146 57614646 44496835 xsdWFqbEFFaW5hID
0b406470 474e4d4a 57597468 6b616839 444c4268 JMNGhtYW9hakhBLD
0b406480 434e6749 47497442 58643531 47534d64 IgNCBtIG15dXdMSG
0b406490 32617064 57646874 6a635639 54597a6c dpa2thdW9VcjlzYT
0b4064a0 56616741 3252754a 304d6f64 79596846 AgaVJuR2doM0FhYy
0b4064b0 54596842 3263704a 30636e6c 30593068 BhYTJpc2lnc0h0Y0
0b4064c0 48497378 47536c4d 57517678 7a536730 xsIHMlSGxvQW0gSz

 

 

So it looks to be a byte array containing viewstate.

Since we are dealing with the large object heap, the next logical step is to look at the contents of the large object heap (remembering that we are in a GC so we might not see the complete heap) to see what we have there.

0:016> !dumpheap -min 85000
The garbage collector data structures are not in a valid state for traversal.
It is either in the "plan phase," where objects are being moved around, or
we are at the initialization or shutdown of the gc heap. Commands related to
displaying, finding or traversing objects as well as gc heap segments may not
work properly. !dumpheap and !verifyheap may incorrectly complain of heap
consistency errors.
------------------------------
Heap 0
Address MT Size
02cb4a2c 001a4738 109,096 1 Free
0ab2ce08 791244f4 1,048,592 3 System.Byte[]
0ac2de18 001a4738 258,192 3 Free
0ac6fec8 791244f4 917,336 3 System.Byte[]
0ad4fe30 7912474c 1,666,080 3 System.Char[]
0aee6a50 791244f4 833,048 3 System.Byte[]
0afb2078 790fa4c8 1,666,072 3 System.String /wEPDwUKMjAxNzA0OTc3Mg9kFgICAw9kFgICAQ8QDxYCHgtfIURhdGFCb3VuZGdkEBWOTjJDQW
0b148ca0 79124304 524,304 3 System.Object[]
0b1c8cc0 79124304 524,304 3 System.Object[]
0b248ce0 790fa4c8 1,666,072 3 System.String /wEPDwUKMjAxNzA0OTc3Mg9kFgICAw9kFgICAQ8QDxYCHgtfIURhdGFCb3VuZGdkEBWOTjJDQW
0b3df908 790fa4c8 158,392 3 System.String /wEWk04Cv62+jwkC+5ieywgClJiipggCgem0hgwCh4zztQEC0vP73QoCvpCj1AQCh7rr9wQC6e+
0b4063d0 791244f4 917,392 3 System.Byte[]
0b4e6370 7912474c 1,666,072 3 System.Char[]
total 13 objects
------------------------------
Heap 1
Address MT Size
06c67d80 001a4738 119,976 1 Free
06c9c130 001a4738 111,820 1 Free
06d30f4c 001a4738 131,104 1 Free
07013420 001a4738 2,232,128 1 Free
total 4 objects
------------------------------
total 17 objects
Statistics:
MT Count TotalSize Class Name
79124304 2 1,048,608 System.Object[]
001a4738 6 2,962,316 Free
7912474c 2 3,332,152 System.Char[]
790fa4c8 3 3,490,536 System.String
791244f4 4 3,716,368 System.Byte[]
Total 17 objects, Total size: 14,549,980

These strange looking strings are Base64 encoded viewstate, so from this we can see that this application has some pages with viewstate around 1.6 MB.  If we were to look at the contents of the byte arrays and char arrays, we would see that these too contain the same type of viewstate strings:

0:016> dc 0ad4fe30 
0ad4fe30 7912474c 000cb608 0077002f 00500045 LG.y..../.w.E.P.
0ad4fe40 00770044 004b0055 006a004d 00780041 D.w.U.K.M.j.A.x.
0ad4fe50 007a004e 00300041 0054004f 00330063 N.z.A.0.O.T.c.3.
0ad4fe60 0067004d 006b0039 00670046 00430049 M.g.9.k.F.g.I.C.
0ad4fe70 00770041 006b0039 00670046 00430049 A.w.9.k.F.g.I.C.
0ad4fe80 00510041 00510038 00780044 00430059 A.Q.8.Q.D.x.Y.C.
0ad4fe90 00670048 00660074 00550049 00680052 H.g.t.f.I.U.R.h.
0ad4fea0 00470064 00430046 00330062 00750056 d.G.F.C.b.3.V.u.
0:016> d
0ad4feb0 0047005a 006b0064 00420045 004f0057 Z.G.d.k.E.B.W.O.
0ad4fec0 006a0054 0044004a 00570051 00670038 T.j.J.D.Q.W.8.g.
0ad4fed0 0057005a 00730056 0032005a 00730035 Z.W.V.s.Z.2.5.s.
0ad4fee0 00530059 00700042 00320062 0034006b Y.S.B.p.b.2.k.4.
0ad4fef0 006d0062 00300074 00440049 00700052 b.m.t.0.I.D.R.p.
0ad4ff00 0043004e 00700042 00790061 00720035 N.C.B.p.a.y.5.r.
0ad4ff10 00470062 00560031 006d0052 00680068 b.G.1.V.R.m.h.h.
0ad4ff20 0057005a 0050004e 00320063 00730078 Z.W.N.P.c.2.x.s.

How do I know they are viewstate? Well, Base64 encoded strings usually start with dDW followed by a long string of gobbelygook, similarily in 2.0 it starts with /wE, and typically when you see these on the LOH it is viewstate.

Taking a step back to look at the facts 

I think most people reading this blog know what viewstate is and what it is used for. If you don't, have a look at Dave Reed's post on truly understanding viewstate.  

For the purposes of this article, there are a few things you need to know

  1. Viewstate tracks the state of a web control
  2. Viewstate is stored as a string in a hidden formfield on the page (Base64encoded) and is serialized and deserialized on each request

 The known truths that we have in this case, from the information above are:

  1. We have high CPU
  2. We have increasing memory usage during the time we have high CPU
  3. Our % Time in GC is high
  4. The ratio between Gen 1 collections and Gen 2 collections is basically 1:1
  5. On at least one occasion during the time we had high CPU a full garbage collection was triggered by decoding large viewstate (on AllThePeople.aspx)
  6. Some pages in the application have very large viewstate (1.6 MB)
  7. To decode viewstate we need to allocate memory for a string and some buffers containing the encoded viewstate, a string and some buffers with decoded viewstate and also a hashtable containing the key/value pairs.

Before I continue, I just want to mention that just because one dump showed that a full collection occurred because we were decoding the viewstate for AllThePeople.aspx, this does not mean that this is necessarily the culprit, but when it comes to looking at dumps of high CPU situations we will have to make some assumptions and move further on those.   What is true though is that it is bad to have large viewstate so whether this is the source of the high CPU or not, some work should definitely be done to reduce it.  I will come to the reasons for this in a little bit.

So, if we look at the facts and make some assumptions to create a good plan for further troubleshooting we can make the following assumptions:

  1. The high CPU in GC is caused by excessive use of the large object heap.  This is almost proven by the fact that we have a 1:1 ratio between Gen 2 and Gen 1 collections, since you will do a full collection (LOH, Gen 2, Gen 1 and Gen 0) anytime you need more space on the large object heap.  If the reverse was true, i.e. that it was not excessive use of the large object heap we would have to do some Gen 1 collections to move items into Gen 2 before there would be a need for a Gen 2 collection, so the ratio would be something like 1:3 or 1:5.  (Keep in mind from previous posts that an ideal ratio is 1:10).
  2. The excessive usage of the LOH is caused by large viewstate.  Again, this is almost completely proven by the fact that the objects that we have found on the Large Object Heap are pretty much exclusively related to viewstate, and that we caught a thread "red-handed" decoding large viewstate.
  3. The AllThePeople.aspx page likely contains some type of large grid, listbox or dropdownlist, showing a large amount of data.  For a page to have a massive amount of viewstate it either has to contain databound controls, for example a dropdownlist with a large amount of rows, or a grid with a large amount of rows shown per datagrid page, or it can contain custom controls that store large amounts of custom viewstate.

If we stop there and take a look at the code for the AppThePeople.aspx page, it looks like this: 

<form id="form1" runat="server">
<div>
Select User: &nbsp;
<asp:DropDownList ID="DropDownList1" runat="server" DataSourceID="SqlDataSource1"
DataTextField="FName" DataValueField="ID" OnSelectedIndexChanged="DropDownList1_SelectedIndexChanged">
</asp:DropDownList>



<asp:SqlDataSource ID="SqlDataSource1" runat="server" ConnectionString="<%$ ConnectionStrings:BigDBConnectionString %>"

ProviderName="<%$ ConnectionStrings:BigDBConnectionString1.ProviderName %>" SelectCommand="SELECT [ID], [FName], [LName], [Address] FROM [Person]"
></asp:SqlDataSource>
<br />
First Name:
<asp:TextBox ID="txtFName" runat="server"></asp:TextBox><br />
Last Name:<asp:TextBox ID="txtLName" runat="server"></asp:TextBox><br />
Address:&nbsp;
<asp:TextBox ID="txtAddress" runat="server"></asp:TextBox>
<asp:Button ID="Button1" runat="server" OnClick="Button1_Click" Text="Button" /></div>
</form>

So basically we have a dropdownlist where the contents are "select ID, FName, LName, Address from Person", and the Person table contains 10.000 rows. That will sure do the trick:)

Of course, our work doesn't stop there.  We would have to look for any additional pages that may have the same issue, and of course also look for ways to resolve this particular issue.

Before we do, just let me mention that I was not able to run a stress test agains this, because not only does this cause the server to go heywire with the GC, but my client couldn't handle sending that many concurrent requests since the data sent back and forth in the viewstate field caused my client to go nuts as well... just some food for thought when you think about how long time the transfer of this data takes for a client, especially if they are on a slow connection.

This brings up an other little detail...

If you look at exceptions in dumps where you have large viewstate you will often find the following type of exception

_ASP.AllThePeople_aspx === System.Web.HttpException: Invalid_Viewstate_Client_Disconnected Client IP: 141.150.12.56 Port: 62164 User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0....) ViewState:
 dDwtNjY5ODIyMjI4O3Q8cDxsPFNUQVJUREFURTtFTkREQVRFO1BMVVN

 

described in http://support.microsoft.com/default.aspx?scid=kb;en-us;555353.

This is not actually an exception that a client will see in the browser, but it occurs because a client got tired of waiting for the full page to load (probably because of the time it took to download the viewstate) so they disconnected before the page finished loading.  That in itself should be an indication that you need to consider reducing the amount of viewstate on the page.

Solutions please!

So what can you do to reduce the viewstate?  A good place to start is by understanding what caused it, so for example in this case, taking a look at the AllThePeople.aspx page and running it with no querystring (or whatever querystring we found earlier during debugging), viewing the source of the page to see how much viewstate we have (in the __VIEWSTATE form field), and understanding why we bring back that much data.

I would also look at some of the other pages in the application that may have controls bound to datasources that may contain a lot of data.

The next step would be to disable viewstate if it is possible, and also allowing the user to filter the data in some way to reduce the amount of data being retreived.   

Let's face it, no user is ever going to drill through 10.000 items in the dropdownlist, so reducing the amount of data doesn't only reduce the amount of viewstate and save the users bandwidth, it also increases the usability of the page greatly.  If they need all the data, they should get it in chunks (i.e. paged datagrid for example), but most of the time filtering is the best option.

I know I might be a bit picky, but usually, if a page on the internet takes more than a few seconds to load, I'm on to the next page.  If it is a web site for internal use where that much data is actually needed, perhaps a thick client would be a better option.   

Now, having said that, it might be ok for a single page that is used very infrequently to use that much viewstate, for example some report that someone only needs to run every 3rd monday of the month if the moon is blue, but for commonly used pages like "default.aspx" some special care is crucial.

Have a weekend y'all...





  • Most cases where I have seen excessive viewstate, there have been one or many things on the page that have viewstate enabled, but which don't actual use the viewstate on postback.

    Its not always so easy, but selectively turning off viewstate on some controls goes a long way towards keeping it under control.

    I find it unfortunate that I can't easily turn off viewstate "by default" an then selectively turn it on for certain pages or turn it off "by default" for a page and only turn it on for some controls. I always have to go the other way, leaving it on globally and trying to turn it off case by case.

    (I haven't dug into this in 2.0 to see if its the same as 1.x )

  • This is so true.  ViewState is a real performance killer.  I am doing some refinement of how I handle ViewState, http://professionalaspnet.com/blogs/aspnet_blog/archive/2006/11/16/Persist-the-ViewState-and-Increase-ASP.NET-Performance.aspx.   I plan on posting an update to this in the next week or so.  One thing I have learned is to not use the GridView Control and minimize the use of any other Web Control in a grid format or on the page itself.  I had a client call me in at the last day before a deadline because they were dumping about 30 MB into viewstate so there would be no postback to process data.  Similar to your scenario.  I told them to just re-architech and take an extra week.

  • Picky? I hardly call that picky ;-)

  • Uno dei blog che maggiormente seguo è quello di Tess Ferrandezprincipalmente incentrato su pratiche di

  • Common Gotcha: Don't forget to when adding providers [Via: ScottGu ] Mounting ISO Images with Vista...

  • Thank you for another great post, Tess!

    ASP.NET 2.0 has these really cool "page state persisters" which allow you to store view state elsewhere (see http://www.aspnetresources.com/blog/page_state_persisters_overview.aspx).

    Even though we're always on the lookout for ways to cut view state in our pages, at times you can't escape it, so we chose to store it in the database.

  • Hi,

    I have a question about high memory usage. We have an issue with one of our SQL servers that results in data not being returned to the application in a timely mannor. when this happens, the connection pool count increases, the number of asp.net requests current increases, and in some cases, the process size jumps from ~200 MB to 400 - 600 MB. In several cases, I have taken a process dump and observed the following from a dumpheap -stat:

           MT      Count     TotalSize Class Name

    0x000fd210        444   458,348,564      Free

    it seems to be high memory usage allocated by 'Free' - is there a way I can determine what's going on here.

    thanks.

    Seth

  • Wow, that is extremely large free sections.

    There is two common ways that you end up with those

    If you dump out !dumpheap -mt 0x00fd210 -min 100000   to get the ones over 100 k, and then compare the addresses of the objects with the output of !eeheap -gc you can check if they fall in one of the small object segments or on the large object segments

    1. If they are on the LOH you have probably allocated a lot of large objects at the same time and just deallocated them.  Since not much if any relocation is done on the LOH you can get a lot of fragmentation here.

    You can run dc on some of the addresses to get a feel for what used to be here, or look at other large objects to get a pattern.

    2. If they are on the small object heap, perhaps you are pinning a lot.  Look at the amount of pinned objects in perfmon for the process or run !gchandles to see how many pinned objects there are.  Since you can't relocated when pinning you'll get a lot of fragmentation then, but in 2.0 that is not so common.

    /Tess

  • I thought I'd share a support story with you from a very interesting case I have. My customer is running

  • Hi,

    I confronted with that problem too. But, I don't understand, why Microsoft's developers didn't fixed this problem. I wrote scipt for "adplus" and run his when CPU-loading was about 100%. Body of script:

    <ADPlus>

       <Settings>

    <Sympath>

    c:\windows\symbols

    </Sympath>

           <RunMode>

                     CRASH

           </RunMode>

           <Option>

                     Quiet

           </Option>

       </Settings>

    <PreCommands>

           <Cmd> .load clr10\sos.dll  </Cmd>

    </PreCommands>

    <Exceptions>

    <Option>

    NoDumpOnFirstChance

    </Option>

    </Exceptions>

       <Breakpoints>

           <NewBP>

               <Address>

    mscorsvr!gc_heap::allocate_large_object

               </Address>

               <Type>

    BP

               </Type>

               <Actions>

    Stack

               </Actions>

    <CustomActions>

    !clrstack;

    </CustomActions>

               <ReturnAction>

                        G

               </ReturnAction>

           </NewBP>

       </Breakpoints>

    </ADPlus>

    Then, I analyzed LOG-file and selected method calls which repeated many times:

    Current stack below ---

    # ChildEBP RetAddr  Args to Child              

    00 02b5f170 792117f6 00014c6c 00000000 00014c6c mscorsvr!gc_heap::allocate_large_object (FPO: [Non-Fpo])

    01 02b5f390 791b6269 023dd040 00014c6c 00000000 mscorsvr!GCHeap::Alloc+0x15b (FPO: [Non-Fpo])

    02 02b5f3a4 791b8873 00014c6c 00000000 00000000 mscorsvr!Alloc+0x3a (FPO: [Non-Fpo])

    03 02b5f3c4 791b8814 02000088 0000a630 00000000 mscorsvr!FastAllocatePrimitiveArray+0x45 (FPO: [Non-Fpo])

    04 02b5f444 0aa64982 02b5f488 223d1cc8 00000000 mscorsvr!JIT_NewArr1+0xbb (FPO: [Non-Fpo])

    WARNING: Frame IP not in any known module. Following frames may be wrong.

    05 02b5f474 791b1967 01ff2d03 00000000 184d3ba8 0xaa64982

    06 02b5f47c 00000000 184d3ba8 02b5f4b8 0aa64649 mscorsvr!JIT_Stelem_Ref+0x49 (FPO: [Non-Fpo])

    Executing custom commands: !clrstack;

    Thread 22

    ESP         EIP      

    0x02b5f414  0x791d550d [FRAME: HelperMethodFrame]

    0x02b5f44c  0x0aa64982 [DEFAULT] [hasThis] String System.Web.UI.LosFormatter.ConsumeOneToken()

    0x02b5f460  0x0aa64739 [DEFAULT] [hasThis] Object System.Web.UI.LosFormatter.DeserializeValueInternal()

    0x02b5f490  0x0aa64649 [DEFAULT] [hasThis] Object System.Web.UI.LosFormatter.DeserializeValueInternal()

    0x02b5f4c0  0x0aa644c9 [DEFAULT] [hasThis] Object System.Web.UI.LosFormatter.DeserializeValueInternal()

    0x02b5f4f0  0x0aa6450e [DEFAULT] [hasThis] Object System.Web.UI.LosFormatter.DeserializeValueInternal()

    0x02b5f520  0x0aa6453c [DEFAULT] [hasThis] Object System.Web.UI.LosFormatter.DeserializeValueInternal()

    0x02b5f550  0x0aa642dc [DEFAULT] [hasThis] Object System.Web.UI.LosFormatter.Deserialize(String)

    0x02b5f578  0x0aa6401e [DEFAULT] [hasThis] Object System.Web.UI.Page.LoadPageStateFromPersistenceMedium()

    0x02b5f5b0  0x0aa63e6b [DEFAULT] [hasThis] Void System.Web.UI.Page.LoadPageViewState()

    0x02b5f5cc  0x038c74f8 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequestMain()

    0x02b5f610  0x038c4e67 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequest()

    0x02b5f64c  0x038c48d3 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequest(Class System.Web.HttpContext)

    0x02b5f654  0x0269e9c4 [DEFAULT] [hasThis] Void System.Web.HttpApplication/CallHandlerExecutionStep.System.Web.HttpApplication+IExecutionStep.Execute()

    0x02b5f664  0x024fe6d0 [DEFAULT] [hasThis] Class System.Exception System.Web.HttpApplication.ExecuteStep(Class IExecutionStep,ByRef Boolean)

    0x02b5f6ac  0x024fdd32 [DEFAULT] [hasThis] Void System.Web.HttpApplication.ResumeSteps(Class System.Exception)

    0x02b5f6f4  0x024fdbfb [DEFAULT] [hasThis] Class System.IAsyncResult System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(Class System.Web.HttpContext,Class System.AsyncCallback,Object)

    0x02b5f710  0x022ece3f [DEFAULT] [hasThis] Void System.Web.HttpRuntime.ProcessRequestInternal(Class System.Web.HttpWorkerRequest)

    0x02b5f74c  0x022ec9f0 [DEFAULT] Void System.Web.HttpRuntime.ProcessRequest(Class System.Web.HttpWorkerRequest)

    0x02b5f758  0x022e8305 [DEFAULT] [hasThis] I4 System.Web.Hosting.ISAPIRuntime.ProcessRequest(I,I4)

    0x02b5f820  0x79217188 [FRAME: ContextTransitionFrame]

    0x02b5f900  0x79217188 [FRAME: ComMethodFrame]

    Then, I look code of method named "ConsumeOneToken()"

    private string ConsumeOneToken()

    {

       int length = 0;

       while (this._current < this._deserializationData.Length)

       {

           switch (this._deserializationData[this._current])

           {

               case ';':

               case '<':

               case '>':

                   return new string(this._builder, 0, length);

               case '\\':

                   this._current++;

                   if (this._deserializationData[this._current] == 'e')

                   {

                       this._current++;

                       return string.Empty;

                   }

                   this._builder[length] = this._deserializationData[this._current];

                   length++;

                   break;

               default:

                   this._builder[length] = this._deserializationData[this._current];

                   length++;

                   break;

           }

           this._current++;

           if (length >= this._builder.Length)

           {

               char[] destinationArray = new char[this._builder.Length + 0x30];

               Array.Copy(this._builder, destinationArray, this._builder.Length);

               this._builder = destinationArray;

               this._recyclable = false;

           }

       }

       return new string(this._builder, 0, length);

    }

    and that code shocked me...

    Tess, please, can you have commenting this???

  • Hi .rip.

    I am not really sure that I am following regarding what shocked you and what it is that should be fixed.

    In this particular case it is deserializing viewstate and in doing so it has to allocate 0x00014c6c bytes (85100 bytes).  The reason for this is that there are many controls on the page or some control on the page which is generating a lot of viewstate.  Most likely a datagrid with a lot of rows in it or a dropdown with a lot of entries.  

    If you see a problem because of this, the best course of action would be to reduce the amount of viewstate generated by the page, both for the sake of mem usage/CPU but also for the sake of bandwidth, especially if you have customers potentially using dial-up or slow connections.

    Tess

  • Thanks for answer!!!

    ...developers could provide some options for buffer's initialization size ("_builder" in code), but haven't made this.

    The following code has surprised me:

    char[] destinationArray = new char[this._builder.Length + 0x30];

    Why "+0x30" ? Why not another value?

    In result, when size of ViewState (after encoding) exceeds 85000, webservice load CPU on 100% some seconds.

    In fact, solution "ViewState" was made very very bad.

    Fortunately, System.Web altered completely in ASP.NET 2.0

  • I can't really comment on the code and why decisions were made since I didn't write it, but surely most code uses constants so why not 0x30:)

    Of course you are welcome to your own opinion about how viewstate was implemented, but if you ask me I would say viewstate is a pretty nice feature, considering how much it gives you for free in terms of state management.  

    If you don't like viewstate as it is implemented there is always the option of turning it off and/or implementing your own:) and I do encourage you to do so in the cases where the generic implementation doesn't fit your needs.  Especially when it comes to selecting which controls should or should not emit viewstate in a given page.

    Everything comes at a cost (cache, viewstate, session and any other state storage) and it is just a matter of finding the right trade-off and figuring out just the right amount that makes the applications performant and usable.  What I am trying to do with this blog is point out what the pitfalls are so that developers can make informed decisions regarding how to use the different features.

Page 1 of 2 (22 items) 12
Leave a Comment
  • Please add 5 and 3 and type the answer here:
  • Post