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)

.NET Memory Leak: XmlSerializing your way to a Memory Leak

.NET Memory Leak: XmlSerializing your way to a Memory Leak

  • Comments 60

I hate to give away the resolution in the title of the blog since it takes away a lot of the suspense:) but I can't figure out a better way to name the blog posts and still keep them nicely searcheable so here we go...

This one has come up a number of times, in fact so many that I finally wrote a kb article on it a couple of years ago. I'll give you the link at the bottom of the blog post.

I specifically remember one time when I had a case on this. It was a Saturday at 2 am and this customer called in with a very urgent server down situation.

The on-call engineer's phone was out of reach for some reason so I got called, and it was one of those rare occasions where you hear the description of the problem and you just throw out a hunch and it happens to be right... Man was I glad to be right... You don't really feel like getting into debugging at 2 am in the morning on a Saturday when a party is going on in your apartment:) and thinking about it, I'm pretty sure that the customer was happy to go home too.

Problem Description

We have continuous memory growth in our ASP.NET application. We don't cache much or use any session state so that doesn't seem to be the problem, but the memory usage just keeps increasing at a steady rate. An attempt to call GC.Collect shows that even a full collection does not reduce the memory usage.

Gathering data

I haven't really mentioned gathering other data than dumps before, but normally when we get memory issues or other performance issues we try to gather performance monitor logs to get a feel for what we are looking at.

The specific counters I would be interested in for memory issues would be:

  • Process/Private Bytes
  • Process/Virtual Bytes
  • .NET CLR Memory/All counters - .NET heaps, time in GC etc.
  • .NET CLR Loading/All counters - Loader Heap, App Domains, Assemblies etc.

Then of course it is always interesting to look at Process/% Processor Time, ASP.NET... /All counters and .NET CLR Exceptions/All counters, but they are usually not all that important for memory issues.

Along with this I would as usual try to take one adplus –hang dump when memory was relatively low (but after all applications were loaded) and one when it was high.

Debugging the issue

I have two dumps, one at 71 MB and the other one at 396 MB.

This issue is a little bit different than the memory issues in the past in that it is not on the .net GC heaps so I think it's time to look at how we do a comparison and figure out where our memory is going in such a case.

Dump 1 Dump 2 How do we find this?
Size of dumps 71 MB 396 MB Windows explorer
GC Heaps 3.5 MB 25.2 MB !eeheap –gc (GC Heap Size)
Loader Heaps 11.8 MB 130 MB !eeheap –loader (Total Loader Heap Size)
Images (dlls) 48.4 MB 48.4 MB !address (RegionUsageImage)
NT Heaps 19.5 MB 50.5 MB !address (RegionUsageHeap)
Virtual Mem 245.9 MB 555.8 MB !address (MEM_RESERVE + MEM_COMMIT)

The perfmon log would be used to see the history of these through out the stress test or process lifetime. In fact, in the case I talked about earlier, it was the performance monitor output that made me zone in on the problem so quickly. So it is a very good complement to dumps in that it can help you spot potential issues, but of course, you don't know the absolute truth until you have looked at the memory dumps.

So what can we see from this? A lot of the increase in memory ~320 MB (396 – 71) seems to come from the loader heap and the NT Heaps... and anytime there is a substantial increase on the loader heap after all applications are loaded it needs to be looked at.

So what is on the loader heap? Assemblies, some class information, hmm... but there is no increase in images so it doesn't really seem like we have a huge increase in the number of .net assemblies/dlls loaded. And running lm (to list all modules) or !peb to list out all loaded modules confirms that there is not a huge number of assemblies. (I have omitted the output of these since it's so long, but please try these commands out in one of your own dumps)

Then what can it be???

Well, looking at the .NET Loading counters in the performance monitor log I find an increase from 15 current assemblies at startup to 5328 when I finish my stress test. WOW! If that is not an increase, I don't know what is...

Let's take a look at what these assemblies are...

If we run !dumpdomain to list the modules loaded in each domain we find that Domain 2 (/LM/w3svc/1/root/MemoryIssues-1-127843748880710932) has a large number of modules listed as unknown module, which means it doesn't have a physical path. In short this means that the module/assembly was dynamically created and not stored to disk, which is also why they don't show up with lm or !peb.

0:000> !dumpdomain
...

Domain 2: 0xf4fa0
LowFrequencyHeap: 0x000f5004
HighFrequencyHeap: 0x000f505c
StubHeap: 0x000f50b4
Name: /LM/w3svc/1/root/MemoryIssues-1-127843748880710932
Assembly: 0x00100850 [System.Web, Version=1.0.5000.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]
ClassLoader: 0x000f71d0
Module Name
0x0013b2b0 c:\windows\assembly\gac\system.web\1.0.5000.0__b03f5f7f11d50a3a\system.web.dll
Assembly: 0x0011d060 [System, Version=1.0.5000.0, Culture=neutral, PublicKeyToken=b77a5c561934e089]
ClassLoader: 0x001012b8
Module Name
0x001496d0 c:\windows\assembly\gac\system\1.0.5000.0__b77a5c561934e089\system.dll
Assembly: 0x000f4638 [System.Xml]
ClassLoader: 0x0015efc8
Module Name
0x01f323b8 c:\windows\assembly\gac\system.xml\1.0.5000.0__b77a5c561934e089\system.xml.dll
Assembly: 0x01f336a8 [System.Web.RegularExpressions]
ClassLoader: 0x00165e60
Module Name
0x01f42120 c:\windows\assembly\gac\system.web.regularexpressions\1.0.5000.0__b03f5f7f11d50a3a\system.web.regularexpressions.dll

...

Assembly: 0x01f8e548 [tfwlio3y]
ClassLoader: 0x01f71c20
Module Name
0x01f8ce80 Unknown Module
Assembly: 0x01f3e338 [4fbkoonb]
ClassLoader: 0x01f73a08
Module Name
0x01f3d588 Unknown Module
Assembly: 0x01f31870 [d68fddbc]
ClassLoader: 0x01f8af48
Module Name
0x01f31068 Unknown Module
Assembly: 0x01f3d768 [ncmnosbh]
ClassLoader: 0x01f37600
Module Name
0x01f83f40 Unknown Module
Assembly: 0x01f30580 [5-we60ay]
ClassLoader: 0x01f84568
Module Name
0x01f84120 Unknown Module
Assembly: 0x01f30df8 [nymoqqrb]
ClassLoader: 0x01f30ec0
Module Name
0x01f9bc40 Unknown Module
Assembly: 0x01fb9be8 [ubg1lguq]
ClassLoader: 0x01fb9cb0
Module Name
0x01fb9f50 Unknown Module
Assembly: 0x01fbaaa8 [crn6r9yj]
ClassLoader: 0x01fbab70
Module Name
0x01fbae10 Unknown Module
Assembly: 0x01fbb988 [3ivrpfyn]
ClassLoader: 0x01fbba50
Module Name
0x01fbbcf0 Unknown Module
Assembly: 0x01f9c8a0 [ar9raomt]
ClassLoader: 0x01f9c968
Module Name
0x01f9cbe0 Unknown Module
Assembly: 0x01f9d748 [8po4sj1t]
ClassLoader: 0x01f9d810
Module Name
0x01f9dad8 Unknown Module
Assembly: 0x00170730 [k3hcfvrs]
ClassLoader: 0x001707f8
Module Name
0x01fa1578 Unknown Module
Assembly: 0x01f98628 [trggh3di]
ClassLoader: 0x01f986f0
Module Name
0x01f98990 Unknown Module

We can also get to these assemblies by running !DumpDynamicAssemblies (!dda) and find that we have 5315 dynamic assemblies in the /LM/w3svc/1/root/MemoryIssues-1-127843748880710932 domain.

0:000> !dda
Domain: ....
-------------------
Domain: 
-------------------
Domain: DefaultDomain
-------------------
Domain: /LM/w3svc/1/root/MemoryIssues-1-127843748880710932
-------------------
Assembly: 0x1f8e548 [tfwlio3y] Dynamic Module: 0x1f8ce80 loaded at: 0xc391000 Size: 0x3200((null))
Assembly: 0x1f3e338 [4fbkoonb] Dynamic Module: 0x1f3d588 loaded at: 0xc551000 Size: 0x3200((null))
Assembly: 0x1f31870 [d68fddbc] Dynamic Module: 0x1f31068 loaded at: 0xc571000 Size: 0x3200((null))
...
Assembly: 0x1f27aba0 [6r53rdxs] Dynamic Module: 0x1f27af28 loaded at: 0x26501000 Size: 0x3200((null))
Assembly: 0x1f27ba28 [ijpwg6f0] Dynamic Module: 0x1f27be38 loaded at: 0x26511000 Size: 0x3200((null))
Assembly: 0x1f27c938 [c3rkovcm] Dynamic Module: 0x1f27cd48 loaded at: 0x26521000 Size: 0x3200((null))
Assembly: 0x1f280dc8 [dvctwism] Dynamic Module: 0x1f2811d8 loaded at: 0x26531000 Size: 0x3200((null))
Assembly: 0x1f281cd8 [xmeznvof] Dynamic Module: 0x1f2820e8 loaded at: 0x26551000 Size: 0x3200((null))
Assembly: 0x1f282870 [wdhhric4] Dynamic Module: 0x1f282c80 loaded at: 0x26541000 Size: 0x3200((null))
Assembly: 0x1f2727a0 [hbxmezcu] Dynamic Module: 0x1f272b90 loaded at: 0x26561000 Size: 0x3200((null))
Assembly: 0x1f273398 [euitep_p] Dynamic Module: 0x1f273bb0 loaded at: 0x26581000 Size: 0x3200((null))
Assembly: 0x1f2746d8 [uxqgnty0] Dynamic Module: 0x1f274b00 loaded at: 0x26591000 Size: 0x3200((null))
Assembly: 0x1f287320 [-oyygxql] Dynamic Module: 0x1f287730 loaded at: 0x265b1000 Size: 0x3200((null))
Assembly: 0x1f275040 [oibxqwve] Dynamic Module: 0x1f286b70 loaded at: 0x265a1000 Size: 0x3200((null))
Assembly: 0x1f287d70 [agqc38wk] Dynamic Module: 0x1f283650 loaded at: 0x265c1000 Size: 0x3200((null))
Assembly: 0x1f284128 [jbfxc_s7] Dynamic Module: 0x1f28b4d0 loaded at: 0x265d1000 Size: 0x3200((null))
Assembly: 0x1f284268 [qvqomxgp] Dynamic Module: 0x1f284640 loaded at: 0x265e1000 Size: 0x3200((null))
--------------------------------------
Total 5,315 Dynamic Assemblies, Total size: 0x40e1600(68,032,000) bytes.
=======================================

Let's take a closer look at one of them (Assembly address: 0x1f2727a0 Module address: 0x1f272b90).

We can dump the module with !dumpmodule

0:000> !dumpmodule 0x1f272b90
Name Unknown Module
dwFlags 0x00000080
Attribute PEFile 
Assembly 0x1f2727a0
LoaderHeap* 0x000f5004
TypeDefToMethodTableMap* 0x26572038
TypeRefToMethodTableMap* 0x26572050
MethodDefToDescMap* 0x265720b4
FieldDefToDescMap* 0x2657212c
MemberRefToDescMap* 0x26572190
FileReferencesMap* 0x265722d8
AssemblyReferencesMap* 0x265722dc
MetaData starts at 0x265644d8 (0x142c bytes)

From the raw MetaData we can see that it is an XMLSerialization.GeneratedAssembly and it seems to have the types XmlSerializationReaderPurchaseOrder and XMLSerializationWriterPurchaseOrder defined.

0:000> dc 0x265644d8 0x265644d8+0x142c
265644d8  424a5342 00010001 00000000 0000000c  BSJB............
265644e8  312e3176 3233342e 00000032 00050000  v1.1.4322.......
...
26564bf8  00001388 00000000 03bc0001 00000000  ................
26564c08  00000000 6f4d3c00 656c7564 6268003e  ......hb
26564c18  7a656d78 642e7563 53006c6c 65747379  xmezcu.dll.Syste
26564c28  6d582e6d 7953006c 6d657473 6c6d582e  m.Xml.System.Xml
26564c38  7265532e 696c6169 6974617a 58006e6f  .Serialization.X
26564c48  65536c6d 6c616972 74617a69 576e6f69  mlSerializationW
26564c58  65746972 6d580072 7265536c 696c6169  riter.XmlSeriali
26564c68  6974617a 72576e6f 72657469 63727550  zationWriterPurc
26564c78  65736168 6564724f 694d0072 736f7263  haseOrder.Micros
26564c88  2e74666f 2e6c6d58 69726553 7a696c61  oft.Xml.Serializ
26564c98  6f697461 65472e6e 6172656e 41646574  ation.GeneratedA
26564ca8  6d657373 00796c62 536c6d58 61697265  ssembly.XmlSeria
26564cb8  617a696c 6e6f6974 64616552 58007265  lizationReader.X
26564cc8  65536c6d 6c616972 74617a69 526e6f69  mlSerializationR
26564cd8  65646165 72755072 73616863 64724f65  eaderPurchaseOrd
26564ce8  58007265 65536c6d 6c616972 72657a69  er.XmlSerializer
26564cf8  6c6d5800 69726553 7a696c61 61427265  .XmlSerializerBa
26564d08  00316573 63727550 65736168 6564724f  se1.PurchaseOrde
26564d18  72655372 696c6169 0072657a 536c6d58  rSerializer.XmlS
26564d28  61697265 657a696c 706d4972 656d656c  erializerImpleme
26564d38  7461746e 006e6f69 536c6d58 61697265  ntation.XmlSeria
26564d48  657a696c 6e6f4372 63617274 654d0074  lizerContract.Me
26564d58  79726f6d 75737349 50007365 68637275  moryIssues.Purch
26564d68  4f657361 72656472 69725700 5f316574  aseOrder.Write1_
26564d78  63727550 65736168 6564724f 64410072  PurchaseOrder.Ad
26564d88  73657264 72570073 32657469 6464415f  dress.Write2_Add
26564d98  73736572 69725700 5f336574 656a624f  ress.Write3_Obje
26564da8  4f007463 72656472 74496465 57006d65  ct.OrderedItem.W
26564db8  65746972 724f5f34 65726564 65744964  rite4_OrderedIte
26564dc8  6e49006d 61437469 61626c6c 00736b63  m.InitCallbacks.
26564dd8  74697257 505f3565 68637275 4f657361  Write5_PurchaseO
26564de8  72656472 74632e00 5200726f 31646165  rder..ctor.Read1
26564df8  7275505f 73616863 64724f65 52007265  _PurchaseOrder.R
26564e08  32646165 6464415f 73736572 61655200  ead2_Address.Rea
26564e18  4f5f3364 63656a62 65520074 5f346461  d3_Object.Read4_
26564e28  6564724f 49646572 006d6574 64616552  OrderedItem.Read
26564e38  75505f36 61686372 724f6573 00726564  6_PurchaseOrder.
26564e48  37316469 6574495f 6d614e6d 64690065  id17_ItemName.id
26564e58  4e5f3131 00656d61 5f386469 70696853  11_Name.id8_Ship
26564e68  74736f43 35646900 6574495f 6900736d  Cost.id5_Items.i
26564e78  4f5f3664 72656472 74496465 69006d65  d6_OrderedItem.i
26564e88  5f363164 61727241 4f664f79 72656472  d16_ArrayOfOrder
26564e98  74496465 69006d65 545f3964 6c61746f  edItem.id9_Total
26564ea8  74736f43 31646900 64415f30 73657264  Cost.id10_Addres
26564eb8  64690073 435f3331 00797469 31326469  s.id13_City.id21
26564ec8  6e694c5f 746f5465 69006c61 535f3364  _LineTotal.id3_S
26564ed8  54706968 6469006f 4c5f3231 31656e69  hipTo.id12_Line1
26564ee8  31646900 74535f34 00657461 5f346469  .id14_State.id4_
26564ef8  6564724f 74614472 64690065 5a5f3531  OrderDate.id15_Z
26564f08  69007069 535f3764 6f546275 006c6174  ip.id7_SubTotal.
26564f18  30326469 6175515f 7469746e 64690079  id20_Quantity.id
26564f28  555f3931 5074696e 65636972 32646900  19_UnitPrice.id2
26564f38  6574495f 6469006d 445f3831 72637365  _Item.id18_Descr
26564f48  69747069 69006e6f 505f3164 68637275  iption.id1_Purch
26564f58  4f657361 72656472 696e4900 73444974  aseOrder.InitIDs
26564f68  65724300 52657461 65646165 72430072  .CreateReader.Cr
26564f78  65746165 74697257 58007265 65526c6d  eateWriter.XmlRe
26564f88  72656461 6e614300 65736544 6c616972  ader.CanDeserial
26564f98  00657a69 69726553 7a696c61 65440065  ize.Serialize.De
26564fa8  69726573 7a696c61 65670065 65525f74  serialize.get_Re
26564fb8  72656461 74656700 6972575f 00726574  ader.get_Writer.
26564fc8  6f63736d 62696c72 73795300 2e6d6574  mscorlib.System.
26564fd8  6c6c6f43 69746365 00736e6f 68736148  Collections.Hash
26564fe8  6c626174 65720065 654d6461 646f6874  table.readMethod
26564ff8  65670073 65525f74 654d6461 646f6874  s.get_ReadMethod
26565008  72770073 4d657469 6f687465 67007364  s.writeMethods.g
26565018  575f7465 65746972 6874654d 0073646f  et_WriteMethods.
26565028  65707974 72655364 696c6169 7372657a  typedSerializers
26565038  74656700 7079545f 65536465 6c616972  .get_TypedSerial
26565048  72657a69 79530073 6d657473 70795400  izers.System.Typ
26565058  61430065 7265536e 696c6169 5200657a  e.CanSerialize.R
26565068  65646165 72570072 72657469 61655200  eader.Writer.Rea
26565078  74654d64 73646f68 69725700 654d6574  dMethods.WriteMe
26565088  646f6874 79540073 53646570 61697265  thods.TypedSeria
26565098  657a696c 53007372 65747379 65532e6d  lizers.System.Se
265650a8  69727563 41007974 776f6c6c 74726150  curity.AllowPart
265650b8  6c6c6169 75725479 64657473 6c6c6143  iallyTrustedCall
265650c8  41737265 69727474 65747562 78626800  ersAttribute.hbx
265650d8  637a656d 006e0075 6f00736e 4e736900  mezcu.n.ns.o.isN
265650e8  616c6c75 00656c62 6465656e 65707954  ullable.needType
265650f8  69725700 754e6574 61546c6c 74694c67  .WriteNullTagLit
26565108  6c617265 6a624f00 00746365 54746547  eral.Object.GetT
26565118  00657079 746e7552 54656d69 48657079  ype.RuntimeTypeH
26565128  6c646e61 65470065 70795474 6f724665  andle.GetTypeFro
26565138  6e61486d 00656c64 65637845 6f697470  mHandle.Exceptio
26565148  7243006e 65746165 6e6b6e55 546e776f  n.CreateUnknownT
26565158  45657079 70656378 6e6f6974 69725700  ypeException.Wri
26565168  74536574 45747261 656d656c 5700746e  teStartElement.W
26565178  65746972 54697358 00657079 70696853  riteXsiType.Ship
26565188  4f006f54 72656472 65746144 69725700  To.OrderDate.Wri
26565198  6c456574 6e656d65 72745374 00676e69  teElementString.
265651a8  6564724f 49646572 736d6574 69725700  OrderedItems.Wri
265651b8  6e456574 656c4564 746e656d 63654400  teEndElement.Dec
265651c8  6c616d69 62755300 61746f54 6d58006c  imal.SubTotal.Xm
265651d8  6e6f436c 74726576 536f5400 6e697274  lConvert.ToStrin
265651e8  72570067 45657469 656d656c 7453746e  g.WriteElementSt
265651f8  676e6972 00776152 70696853 74736f43  ringRaw.ShipCost
26565208  746f5400 6f436c61 4e007473 00656d61  .TotalCost.Name.
26565218  74697257 74744165 75626972 4c006574  WriteAttribute.L
26565228  31656e69 74694300 74530079 00657461  ine1.City.State.
26565238  0070695a 576c6d58 65746972 72570072  Zip.XmlWriter.Wr
26565248  54657469 64657079 6d697250 76697469  iteTypedPrimitiv
26565258  74490065 614e6d65 4400656d 72637365  e.ItemName.Descr
26565268  69747069 55006e6f 5074696e 65636972  iption.UnitPrice
26565278  61755100 7469746e 694c0079 6f54656e  .Quantity.LineTo
26565288  006c6174 74697257 61745365 6f447472  tal.WriteStartDo
26565298  656d7563 5400746e 654c706f 456c6576  cument.TopLevelE
265652a8  656d656c 6300746e 6b636568 65707954  lement.checkType
265652b8  61655200 6c754e64 6d58006c 6175516c  .ReadNull.XmlQua
265652c8  6966696c 614e6465 4700656d 73587465  lifiedName.GetXs
265652d8  70795469 706f0065 7571455f 74696c61  iType.op_Equalit
265652e8  65670079 614e5f74 6700656d 4e5f7465  y.get_Name.get_N
265652f8  73656d61 65636170 6f6f4200 6e61656c  amespace.Boolean
26565308  58734900 736e6c6d 72747441 74756269  .IsXmlnsAttribut
26565318  6e550065 776f6e6b 646f4e6e 6f4d0065  e.UnknownNode.Mo
26565328  6f546576 7478654e 72747441 74756269  veToNextAttribut
26565338  6f4d0065 6f546576 6d656c45 00746e65  e.MoveToElement.
26565348  5f746567 6d457349 45797470 656d656c  get_IsEmptyEleme
26565358  5300746e 0070696b 64616552 72617453  nt.Skip.ReadStar
26565368  656c4574 746e656d 6c6d5800 65646f4e  tElement.XmlNode
26565378  65707954 766f4d00 436f5465 65746e6f  Type.MoveToConte
26565388  6700746e 4e5f7465 5465646f 00657079  nt.get_NodeType.
26565398  5f746567 61636f4c 6d614e6c 65670065  get_LocalName.ge
265653a8  614e5f74 7073656d 55656361 52004952  t_NamespaceURI.R
265653b8  45646165 656d656c 7453746e 676e6972  eadElementString
265653c8  72724100 45007961 7275736e 72724165  .Array.EnsureArr
265653d8  6e497961 00786564 64616552 45646e45  ayIndex.ReadEndE
265653e8  656d656c 5300746e 6e697268 7272416b  lement.ShrinkArr
265653f8  54007961 6365446f 6c616d69 74656700  ay.ToDecimal.get
26565408  6c61565f 52006575 54646165 64657079  _Value.ReadTyped
26565418  6d697250 76697469 6f540065 33746e49  Primitive.ToInt3
26565428  72430032 65746165 6e6b6e55 4e6e776f  2.CreateUnknownN
26565438  4565646f 70656378 6e6f6974 6c6d5800  odeException.Xml
26565448  656d614e 6c626154 65670065 614e5f74  NameTable.get_Na
26565458  6154656d 00656c62 00646441 526c6d78  meTable.Add.xmlR
26565468  65646165 626f0072 7463656a 65536f54  eader.objectToSe
26565478  6c616972 00657a69 74697277 72007265  rialize.writer.r
26565488  65646165 6d580072 7265536c 696c6169  eader.XmlSeriali
26565498  6974617a 65476e6f 6172656e 43646574  zationGeneratedC
265654a8  0065646f 5f746567 65746e49 6c616e72  ode.get_Internal
265654b8  636e7953 656a624f 53007463 65747379  SyncObject.Syste
265654c8  68542e6d 64616572 00676e69 696e6f4d  m.Threading.Moni
265654d8  00726f74 65746e45 65730072 74495f74  tor.Enter.set_It
265654e8  45006d65 00746978 65707974 00000000  em.Exit.type....
265654f8  00501b00 00720075 00680063 00730061  ..P.u.r.c.h.a.s.
26565508  004f0065 00640072 00720065 0d000100  e.O.r.d.e.r.....
26565518  00680053 00700069 006f0054 004f1300  S.h.i.p.T.o...O.
26565528  00640072 00720065 00610044 00650074  r.d.e.r.D.a.t.e.
26565538  00490b00 00650074 0073006d 004f1700  ..I.t.e.m.s...O.
26565548  00640072 00720065 00640065 00740049  r.d.e.r.e.d.I.t.
26565558  006d0065 00531100 00620075 006f0054  e.m...S.u.b.T.o.
26565568  00610074 1100006c 00680053 00700069  t.a.l...S.h.i.p.
26565578  006f0043 00740073 00541300 0074006f  C.o.s.t...T.o.t.
26565588  006c0061 006f0043 00740073 00410f00  a.l.C.o.s.t...A.
26565598  00640064 00650072 00730073 004e0900  d.d.r.e.s.s...N.
265655a8  006d0061 0b000065 0069004c 0065006e  a.m.e...L.i.n.e.
265655b8  09000031 00690043 00790074 00530b00  1...C.i.t.y...S.
265655c8  00610074 00650074 005a0700 00700069  t.a.t.e...Z.i.p.
265655d8  00412500 00720072 00790061 0066004f  .%A.r.r.a.y.O.f.
265655e8  0072004f 00650064 00650072 00490064  O.r.d.e.r.e.d.I.
265655f8  00650074 1100006d 00740049 006d0065  t.e.m...I.t.e.m.
26565608  0061004e 0065006d 00441700 00730065  N.a.m.e...D.e.s.
26565618  00720063 00700069 00690074 006e006f  c.r.i.p.t.i.o.n.
26565628  00551300 0069006e 00500074 00690072  ..U.n.i.t.P.r.i.
26565638  00650063 00511100 00610075 0074006e  c.e...Q.u.a.n.t.
26565648  00740069 13000079 0069004c 0065006e  i.t.y...L.i.n.e.
26565658  006f0054 00610074 0f00006c 006e0061  T.o.t.a.l...a.n.
26565668  00540079 00700079 41000065 00740068  y.T.y.p.e..Ah.t.
26565678  00700074 002f003a 0077002f 00770077  t.p.:././.w.w.w.
26565688  0077002e 002e0033 0072006f 002f0067  ..w.3...o.r.g./.
26565698  00300032 00310030 0058002f 004c004d  2.0.0.1./.X.M.L.
265656a8  00630053 00650068 0061006d 004d4700  S.c.h.e.m.a..GM.
265656b8  006d0065 0072006f 00490079 00730073  e.m.o.r.y.I.s.s.
265656c8  00650075 002e0073 00750050 00630072  u.e.s...P.u.r.c.
265656d8  00610068 00650073 0072004f 00650064  h.a.s.e.O.r.d.e.
265656e8  003a0072 003a003a 0054003a 00750072  r.:.:.:.:.T.r.u.
265656f8  003a0065 00522700 00610065 00360064  e.:..'R.e.a.d.6.
26565708  0050005f 00720075 00680063 00730061  _.P.u.r.c.h.a.s.
26565718  004f0065 00640072 00720065 00572900  e.O.r.d.e.r..)W.
26565728  00690072 00650074 005f0035 00750050  r.i.t.e.5._.P.u.
26565738  00630072 00610068 00650073 0072004f  r.c.h.a.s.e.O.r.
26565748  00650064 00000072 b41e11ac 46920e8c  d.e.r..........F
...
265658d8  01070339 0020041c 20045912 030e0e01  9..... ..Y. ....
265658e8  041c0000 1c010100 01022005 07051c1c  ......... ......
265658f8  1c251202 00000104 00000000 0000492c  ..%.........,I..

... or we can save it to disk

0:000> !dda -save g:\blog 0x1f2727a0 
Writing Dynamic modules to disk.

In which case it gets saved as hbxmezcu.dll (per above), and we can open it up in reflector for example and from there find out that it contains a class Microsoft.XML.Serialization.GeneratedAssembly/PurchaseOrderSerializer.

If we don’t pass a specific assembly address the –save switch will save all dynamic assemblies.

In fact, if we dump a few more of these we find that they look almost identical. They define the same classes...

So, what are these and why are there so many of them? It would seem that whatever they are we would at least only need one.

Bringing it all together

My code is a slight rewrite of an XmlSerializer sample from MSDN.

Searching my code for PurchaseOrder, I find this line of code in page_load of one of my pages

XmlSerializer serializer = new XmlSerializer(typeof(PurchaseOrder), new XmlRootAttribute(""));

This would seem like a pretty innocent piece of code. We create an XMLSerializer for PurchaseOrder. But what happens under the covers?

If we take a look at the XmlSerializer constructor with Reflector we find that it calls

this.tempAssembly = XmlSerializer.GenerateTempAssembly(this.mapping, type, defaultNamespace, location, evidence);

which generates a temp (dynamic) assembly. So every time this code runs (i.e. every time the page is hit) it will generate a new assembly.

The reason it generates an assembly is that it needs to generate functions for serializing and deserializing and these need to reside somewhere.

Ok, fine... it creates an assembly, so what? When we’re done with it, it should just disappear right?

Well... an assembly is not an object on the GC Heap, the GC is really unaware of assemblies, so it won’t get garbage collected. The only way to get rid of assemblies in 1.0 and 1.1 is to unload the app domain in which it resides.

And therein lies the problem Dr Watson.

What is the solution?

The default constructors XmlSerializer(type) and XmlSerializer(type, defaultNameSpace) caches the dynamic assembly so if you use those constructors only one copy of the dynamic assembly needs to be created.

Seems pretty smart... why not do this in all constructors? Hmm... interesting idea, wonder why they didn’t think of that one:) Ok, the other constructors are used for special cases, and the assumption would be that you wouldn’t create a ton of the same XmlSerializers using those special cases, which would mean that we would cache a lot of items we later didn’t need and use up a lot of extra space. Sometimes you have to do what is good for the majority of the people.

So what do you do if you need to use one of the other constructors? My suggestion would be to cache the XmlSerializer if you need to use it often. Then it would only be created once.

For more info see http://support.microsoft.com/kb/886385/en-us

Some other constructs that exhibit the same problems

Temporary assemblies are also used for regular expressions, as well as script blocks in XSL Transforms. In the case of the script blocks I would suggest using XSLT extension objects or cache the transform.

Have fun, and don’t play with XmlSerialization at 2 am in the morning on a Saturday night:)  

 





  • 一个.net开发的网站项目现在到了收尾阶段,但突然发现一个问题:网站访问量不高,占用内存却长地飞快,甚至2,3个小时内存使用就上涨到了1g多,非常郁闷。google了一下,查到了几篇相关文章。无法卸...

  • Hi Tess,

    I'm debugging a slightly different beast that happens only on certain m/cs in our environment. First a quick background on the environments:

    - all m/cs are running on Windows Server 2003, SP1 (Std Edition) IIS 6.0

    - 4 GB memory

    - Both .NET 1.1 & 2.0 installed

    - number of hotfixes applied

    Initial investigation lead me to believe that a possible memory leak in "private bytes" was specific to our web service implementation. So we eventually stubbed out all app specific code & still saw the private bytes increase steadily until the worker process recycled because it reached the "Maximum used memory" limit for the App Pool config.

    To confirm the theory that app related stuff wasn't the culprit, i then created a basic "HelloWorld" web service & set the app pool settings to recycle the worker process when the "Maximum used memory" reached 50MB. Ran the test... private bytes increased steadily and eventually the worker process recycled.

    I re-ran this same test on a different m/c (same OS level, 2GB memory but a slightly different set of hotfixes applied to it). Here the HelloWorld app does NOT exhibit the leak (which is what i was expecting).

    I've tried analysing by gathering minidumps, VA dumps, perf logs - the only thing that stands out between the leaking/non-leaking servers is the Heap size.

    Here are some excerpts from the VADump for the leaking case (dumps were taken roughly 45secs apart):

    Category                        Total        Private Shareable    Shared

                              Pages    KBytes    KBytes    KBytes    KBytes

         Page Table Pages        84       336       336         0         0

         Other System            39       156       156         0         0

         Code/StaticData       3782     15128      1312      2736     11080

         Heap                 14184     56736     56736         0         0

         Stack                   79       316       316         0         0

         Teb                     33       132       132         0         0

         Mapped Data            165       660         0       104       556

         Other Data            3179     12716     12712         4         0

         Total Modules         3782     15128      1312      2736     11080

         Total Dynamic Data   17640     70560     69896       108       556

         Total System           123       492       492         0         0

    Grand Total Working Set    21545     86180     71700      2844     11636

    Category                        Total        Private Shareable    Shared

                              Pages    KBytes    KBytes    KBytes    KBytes

         Page Table Pages        97       388       388         0         0

         Other System            51       204       204         0         0

         Code/StaticData       3790     15160      1312      2756     11092

         Heap                 30298    121192    121192         0         0

         Stack                   79       316       316         0         0

         Teb                     33       132       132         0         0

         Mapped Data            165       660         0       104       556

         Other Data            3179     12716     12712         4         0

         Total Modules         3790     15160      1312      2756     11092

         Total Dynamic Data   33754    135016    134352       108       556

         Total System           148       592       592         0         0

    Grand Total Working Set    37692    150768    136256      2864     11648

    Category                        Total        Private Shareable    Shared

                              Pages    KBytes    KBytes    KBytes    KBytes

         Page Table Pages       106       424       424         0         0

         Other System            60       240       240         0         0

         Code/StaticData       3792     15168      1312      2756     11100

         Heap                 39342    157368    157368         0         0

         Stack                   80       320       320         0         0

         Teb                     34       136       136         0         0

         Mapped Data            165       660         0       104       556

         Other Data            3182     12728     12724         4         0

         Total Modules         3792     15168      1312      2756     11100

         Total Dynamic Data   42803    171212    170548       108       556

         Total System           166       664       664         0         0

    Grand Total Working Set    46761    187044    172524      2864     11656

    The Heap pages show the increase while the GC Heap (Other Data) does not show any increase at all (this is what I see in the PerfMon logs as well). What/why is there a dramatic increase in the heap allocations (especially, private bytes)?

    The other thing I see in the mini dumps is that the number of System.String objects & size is seemingly high in the m/c where the leak is happening whereas those values are much lower on the server where it isn’t leaking.

    Can you shed some light on what else should I be looking at? Our production web servers are exhibiting this behavior and we've been unable to figure out why. Please help!

    Thanks.

    PS: btw, i've learned a lot from reading thru your blogs & without them, i wouldn't have gotten the faintest clue on what to look for.

  • Not sure if this is relevant (perhaps, it is) - the Windows Server 2003 m/cs use the /3GB switch in the boot.ini file.

  • This is a problem with WCF using the XmlSerializer!!!!!!    [System.ServiceModel.XmlSerializerFormatAttribute()]

    Using Process Explorer, we see the temp assemblies growing unless we declare the client proxy as static.  Unfortunately a lot of developers will be hit by this problem if Microsoft does not get a fix.  The solution is not to use the DataContractSerializer (which we assume does not have the problem).  We would have to re-tool all our classes.

    This is a huge problem for our application which runs out of memory by the end of the day with 100 or so users.  This bug does not make moving to WebServices easier - Microsoft should release a patch for this immediately!!!!

  • Hi Marty,

    I haven't really worked a whole lot with WCF so I don't know the details regarding the problem you're talking about but before going to deep into it I just want to see if it is a real problem or a percieved problem.

    When you call a webservice from ASP.NET for example you will also create dynamic assemblies for xml serialization of the parameters but you will only create one per type/method so after initially you will create a few but once they are all initialized they will be reused since they are created with the default constructors.     Are you saying that with this construct you keep creating new ones throughout the life of the process?  I.e. if you call the same web service twice, will you create new assemblies?  

    If you do continually create new ones for each call to the ws, please post some sample code and I will take a look if time permits or start a case with support.   If the 2nd call to a web service does not generate new assemblies your memory problem lies elsewhere.  You will need to generate at least one new assembly per type you serialize otherwise serialization will not work...

    Thanks

    Tess

  • Hi Tess, thanks for the reply!!!

    just a summary again of what we are experiencing... we are trying to get this to Microsoft.

    We have experienced the documented XmlSerializer assembly leak problem reported by Microsoft as a problem with the .NET Framework 1.0, 1.1 and 2.0.

    http://support.microsoft.com/kb/886385/en-us

    Specifically, we use WCF to generate client proxies to WebServices and we also instruct WCF to use the XmlSerializerFormatter and not the DataContractFormatter.

    Because we rely on the XmlSerializerFormatter, we have no control over the WCF code that deserializes xml data streams into managed objects.  The call to Deserialize from the Service Model exhibits the problem.  The call to deserialize uses a constructor of the XmlSerializer that does not cache assemblies based on the type.  And it is very easy to duplicate by using Process/App Domain Viewer - Current and Total Assemblies counts grow.

    See stack trace below.

    We have a workaround whereby we cache the client proxy classes but we feel that this is not an ideal solution long term.

    Ideally, we would like a patch to the Service Model framework (WCF) that addresses the problem when invoking the XmlSerializer by caching the serializer in the assembly (as described) or better yet, a path to the XmlSerializer that implements caching in ALL constructors.

    Stack Trace (Crude cut and paste - please forgive me).

    qtnaxaft!Microsoft.Xml.Serialization.GeneratedAssembly.ArrayOfObjectSerializer1.Deserialize(System.Xml.Serialization.XmlSerializationReader reader = {Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializationReaderIPlanDesign}) + 0x40 bytes

    System.Xml.dll!System.Xml.Serialization.XmlSerializer.Deserialize(System.Xml.XmlReader xmlReader = {Element, Name="a:OfferingCombination"}, string encodingStyle, System.Xml.Serialization.XmlDeserializationEvents events) + 0xa2 bytes

    System.Xml.dll!System.Xml.Serialization.XmlSerializer.Deserialize(System.Xml.XmlReader xmlReader, string encodingStyle) + 0x21 bytes

    System.ServiceModel.dll!System.ServiceModel.Dispatcher.XmlSerializerOperationFormatter.DeserializeBody(System.Xml.XmlDictionaryReader reader, System.ServiceModel.Channels.MessageVersion version, System.Xml.Serialization.XmlSerializer serializer, System.ServiceModel.Description.MessagePartDescription returnPart = Name={GetOfferingCombinationsResult}, Namespace="http://tempuri.org/", Type={System.Void}, Index=0}, System.ServiceModel.Description.MessagePartDescriptionCollection bodyParts = Count = 1, object[] parameters = {Dimensions:[1]}, bool isRequest = false) + 0x63 bytes

    System.ServiceModel.dll!System.ServiceModel.Dispatcher.XmlSerializerOperationFormatter.DeserializeBody(System.Xml.XmlDictionaryReader reader, System.ServiceModel.Channels.MessageVersion version, string action, System.ServiceModel.Description.MessageDescription messageDescription, object[] parameters, bool isRequest) + 0x137 bytes

    System.ServiceModel.dll!System.ServiceModel.Dispatcher.OperationFormatter.DeserializeBodyContents(System.ServiceModel.Channels.Message message, object[] parameters, bool isRequest) + 0x95 bytes

    System.ServiceModel.dll!System.ServiceModel.Dispatcher.OperationFormatter.DeserializeReply(System.ServiceModel.Channels.Message message, object[] parameters) + 0x198 bytes

    System.ServiceModel.dll!System.ServiceModel.Dispatcher.ProxyOperationRuntime.AfterReply(ref System.ServiceModel.Dispatcher.ProxyRpc rpc = {System.ServiceModel.Dispatcher.ProxyRpc}) + 0x33 bytes

    System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannel.HandleReply(System.ServiceModel.Dispatcher.ProxyOperationRuntime operation = {System.ServiceModel.Dispatcher.ProxyOperationRuntime}, ref System.ServiceModel.Dispatcher.ProxyRpc rpc = {System.ServiceModel.Dispatcher.ProxyRpc}) + 0xd8 bytes

    System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannel.EndCall(string action, object[] outs, System.IAsyncResult result) + 0xde bytes

    System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannelProxy.InvokeEndService(System.Runtime.Remoting.Messaging.IMethodCallMessage methodCall = {System.Runtime.Remoting.Messaging.Message}, System.ServiceModel.Dispatcher.ProxyOperationRuntime operation = {System.ServiceModel.Dispatcher.ProxyOperationRuntime}) + 0x45 bytes

    System.ServiceModel.dll!System.ServiceModel.Channels.ServiceChannelProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage message = {System.Runtime.Remoting.Messaging.Message}) + 0x81 bytes

    mscorlib.dll!System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(ref System.Runtime.Remoting.Proxies.MessageData msgData, int type) + 0x273 bytes

  • Can/does the same problem occur if you implement iXmlSerializable in an ASP.Net application.

  • Hi Chad,

    The only reason it would make the same problem occurr would be if someone called new XmlSerializer with one of the constructors listed above...   just implementing iXmlSerializable would not cause an issue...

  • Hi Tess,

    I'm currently working on a big project involving several WCF services. We have big performance and memory consumption problems for 3 of them.

    These 3 services are actually designed to act as gateways for external partners Java webservices.

    We used svcutil to generate the client proxy to call these services and we saw that WCF runtime is generating an on-the-fly XMLSerializer assembly *for each call* to the remote WS. As you described, we saw that unfortunately a new assembly is generated each time we call the same method.

    We tried many things to solve this problem : SGEN generation, we also tried to used different option of the svcutil generation to change the type of Formatter(DataContractFormatter, XmlSerializerFormatter),...

    But - as marty explainded in his comment- we're also running out of memory during our load test with only 100 users.

    We're exploring this problem with the MS premium support because we think that our perf and memory leak problem is coming from this strange WCF behaviour but we're running out of ideas and the problem is still there !

    Do you have any news of Marty's problem?

    Do you know if a fix has been published?

    Thanks a lot!

  • To be honest I haven't worked with WCF enough to be able to give you any answers off-hand.  For "normal" webservices you would only create one per type, but perhaps WCF uses one of the non-standard constructors... One idea, in order to figure out if this is the case, would be to run a test in a controlled environment where you set a breakpoint with !bpmd -md <methoddesc> on the different XmlSerializer..ctor  (constructors)

    you can get the method descriptors by doing !dumpheap to find the methodtable for XmlSerializer and then doing !dumpmt -md on that methodtable.

    At least that could tell you why you create new assemblies all the time.

  • We have the exact same issue... new assemblies getting created on every call.  We have contracts for every object but am still seeing many references to:

    [System.Xml.Serialization.XmlElementAttribute(IsNullable=true)]

    Is there any update on a solution?

  • For us it appears the issue is solved with .NET 2.0 SP1 that was released on 12/27.  We are confirming with more tests but it appears fixed.  And performance appears 100 times faster.

  • i'm not good at english :(

    i happened Marty's problem and solved it ! we use wcf to call services ,and so of the service are .asmx . And the proxy of the .asmx service is the problem . It serializ and deserialize every time that we call it. so the cup and memory are very high.

    just do :

    we use a object pool that cache the client proxy.

    code:

    public interface IWcfClientPoolElement<TClient> where TClient : IWcfClientPoolElement<TClient>, new()

       {

           WcfClientPool<TClient> Pool

           {

               get;

               set;

           }

       }

       public class WcfClientPool<TClient> where TClient : IWcfClientPoolElement<TClient>, new()

       {

           private Stack<TClient> m_container;

           private int m_currentCount;

           private int m_capacity;

           private object m_mutex;      

           public WcfClientPool() : this(20) { }

           public WcfClientPool(int capacity)

           {

               this.m_capacity = capacity;

               this.m_container = new Stack<TClient>();

               this.m_mutex = new object();

               this.m_currentCount = 0;

           }

           public TClient GetClient()

           {

               while (true)

               {

                   lock (this.m_mutex)

                   {

                       if (this.m_container.Count > 0)

                       {

                           return this.m_container.Pop();

                       }

                       else if (this.m_currentCount < this.m_capacity)

                       {

                           this.m_currentCount++;

                           TClient client = new TClient();

                           client.Pool = this;

                           return client;

                       }

                       else

                       {

                           Thread.SpinWait(100);

                       }

                   }

               }

           }

           public void Restore(TClient client)

           {

               lock (m_mutex)

               {

                   this.m_container.Push(client);

               }

           }

       }

    and

    client code like this :

    [System.Diagnostics.DebuggerStepThroughAttribute()]

    [System.CodeDom.Compiler.GeneratedCodeAttribute("System.ServiceModel", "3.0.0.0")]

    public partial class I_UserSoapClient : System.ServiceModel.ClientBase<I_UserSoap>, I_UserSoap,System.IDisposable,

       Temporary.IWcfClientPoolElement<I_UserSoapClient>

    {

       private Temporary.WcfClientPool<I_UserSoapClient> pool = null;

       void System.IDisposable.Dispose()

       {

           Pool.Restore(this);

       }

    .....

    if you have any question ,please add me msn : flyingchen@live.com

  • we can use below way to use the proxy :

    using (I_UserSoapClient objClient = pool.GetClient())

  • As you already know, i spend my days analyzing dumps for customers, and more often than not I don't have

Page 3 of 4 (60 items) 1234
Leave a Comment
  • Please add 4 and 5 and type the answer here:
  • Post