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 Debugging Demos Lab 6: Debugging Challenge (Memory leak)

.NET Debugging Demos Lab 6: Debugging Challenge (Memory leak)

  • Comments 4

Here is the debugging challenge for lab 6... this one is really tricky...

I will post the step-by-step instructions and review in about a week, but for now I will only post a problem description.

As with lab 5, your mission, should you choose to accept it, is to troubleshoot the problem with only that problem description.  Post intermediate findings, questions, potential solutions etc. in the comments, and don't worry if you go down the wrong path a couple of times (that's just part of the debugging experience:)). Try not to peak at the code unless you have identified a problematic function during the troubleshooting process...

Btw, I realized when I started counting the problems I had introduced in the buggy bits website that there will only be 7 labs (which technically speaking is around 10, but of course it isn't 10:))  On the flip side I think these 7 labs account for most of the major buckets we typically troubleshoot, but I might create a new lab set at a later time.

Problem description:

We have started getting out of memory exceptions on the buggy bits site and we have been able to determine a scenario in which we think we are leaking memory but we can't seem to figure out where the memory is going. 

The leak seems to be occurring on our ProductInfo page for example

http://localhost/BuggyBits/ProductInfo.aspx?ProductName=Bugspray

and we can reproduce it by stress testing.  

It seems like it is leaking just a small bit every time but since it is something that customers look at a lot and over time the process will crash with an out of memory exception.  

Any help is greatly appreciated!

 

Hint: you can use tinyget with 50 threads and loop 20 to generate a leak.  This will not cause a major leak but should be big enough for you to troubleshoot. 

The challenge is on:)
Tess

Previous demos and setup instructions

If you are new to the debugging labs, here you can find information on how to set up the labs as well as links to the previous labs in the series.

Information and setup instructions
Lab 1: Hang
Lab 1: Hang - review
Lab 2: Crash
Lab 2: Crash - review
Lab 3: Memory
Lab 3: Memory - review
Lab 4: High CPU hang
Lab 4: High CPU hang - review
Lab 5: Crash
Lab 5: Crash - review

  • Hello,

    since this was a memory leak case, the first thing i did was to take 2 different dumps at different

    moments so that i could compare differences so to know where to start looking.

    Also i used somer perf counters like virtual bytes, private bytes, CLR. Memory and CLR. Loading

    After getting the dumps, the first thing was to look at the perf counters to see where are

    the biggest differences.

    Things i noticed in perf counters: assembly loading was getting up, loader heap was algo increasing and virtual memory

    was also increasing.

    Next i opened both dumps and done a !eeheap -loader

    In my first dump i had

    (...)

    Module 07bdb62c: Size: 0x0(0)bytes.

    Module 07bdbc0c: Size: 0x0(0)bytes.

    Module 07bdc1ec: Size: 0x0(0)bytes.

    Module 07bdc7cc: Size: 0x0(0)bytes.

    Total size: 0x0(0)bytes

    --------------------------------------

    Total LoaderHeap size: 0x277000(2584576)bytes

    =======================================

    In my second dump i have

    (...)

    Module 09fa7b6c: Size: 0x0(0)bytes.

    Module 09fa814c: Size: 0x0(0)bytes.

    Module 09fa872c: Size: 0x0(0)bytes.

    Module 09fa8d0c: Size: 0x0(0)bytes.

    Total size: 0x0(0)bytes

    --------------------------------------

    Total LoaderHeap size: 0x672000(6758400)bytes

    =======================================

    This means i had a increase due to assembly loading because it´s not suppose to

    keep on growing

    Then i did a !dumpdomain

    and i see a lot of this

    Assembly: 07847a98 [zhk22pzk, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null]

    ClassLoader: 07847b30

    SecurityDescriptor: 07847998

     Module Name

    09fa814c zhk22pzk, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null

    Assembly: 07848700 [9cqj_cx8, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null]

    ClassLoader: 07848798

    SecurityDescriptor: 07848600

     Module Name

    09fa872c 9cqj_cx8, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null

    Assembly: 07849368 [ol2fh7hw, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null]

    ClassLoader: 07849400

    SecurityDescriptor: 07849268

     Module Name

    09fa8d0c ol2fh7hw, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null

    With this kind of names it´s probably some dynamic assembly

    Next i tried to see what´s inside each one of this

    0:000> !dumpmodule 09fa8d0c

    Name: ol2fh7hw, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null

    Attributes: PEFile

    Assembly: 07849368

    LoaderHeap: 00000000

    TypeDefToMethodTableMap: 0a14153c

    TypeRefToMethodTableMap: 0a141554

    MethodDefToDescMap: 0a1415b4

    FieldDefToDescMap: 0a141620

    MemberRefToDescMap: 0a14164c

    FileReferencesMap: 0a14173c

    AssemblyReferencesMap: 0a141740

    MetaData start address: 0a1509e4 (4184 bytes)

    When i tried to save the module to find what´s going on inside i get this

    0:000> lmvm ol2fh7hw

    start    end        module name

    0a150000 0a152200   ol2fh7hw   (deferred)            

       Image path: ol2fh7hw.dll

       Image name: ol2fh7hw.dll

       Using CLR debugging support for some symbols

       Has CLR image header, track-debug-data flag not set

       Timestamp:        Sat Mar 08 10:03:50 2008 (47D26486)

       CheckSum:         00000000

       ImageSize:        00002200

       Translations:     0000.04b0 0000.04e0 0409.04b0 0409.04e0

    0:000> !savemodule 0a150000 c:\d.dll

    3 sections in file

    section 0 - VA=2000, VASize=1894, FileAddr=200, FileSize=1a00

    section 1 - VA=4000, VASize=2a8, FileAddr=1c00, FileSize=400

    section 2 - VA=6000, VASize=c, FileAddr=2000, FileSize=200

    Fail to read memory

    In the generated dll the only thing i see is a Object reference not set...

    Here is my first question: any thoughts on why this happened?

    Next i pickup the MetaData start address: 0a1509e4 (4184 bytes)

    and tried to look inside using dc

    !dc 0a1509e4

    After a couple of dc´s i got

    0:000> dc

    0a150f64  00020007 00090016 00170002 8004000b  ................

    0a150f74  00000000 00000000 00000000 00000000  ................

    0a150f84  0000045e 00000002 00000000 00000000  ^...............

    0a150f94  00b80001 00000000 00000000 00000000  ................

    0a150fa4  00000000 01430000 00000000 00000002  ......C.........

    0a150fb4  00000000 00000000 029d0001 00000000  ................

    0a150fc4  00000000 6f4d3c00 656c7564 6c6f003e  .....<Module>.ol

    0a150fd4  37686632 642e7768 58006c6c 65536c6d  2fh7hw.dll.XmlSe

    0:000> dc

    0a150fe4  6c616972 74617a69 576e6f69 65746972  rializationWrite

    0a150ff4  6f725072 74637564 63694d00 6f736f72  rProduct.Microso

    0a151004  582e7466 532e6c6d 61697265 617a696c  ft.Xml.Serializa

    0a151014  6e6f6974 6e65472e 74617265 73416465  tion.GeneratedAs

    0a151024  626d6573 5800796c 65536c6d 6c616972  sembly.XmlSerial

    0a151034  74617a69 526e6f69 65646165 6f725072  izationReaderPro

    0a151044  74637564 6c6d5800 69726553 7a696c61  duct.XmlSerializ

    0a151054  00317265 646f7250 53746375 61697265  er1.ProductSeria

    (...)

    0:000> dc

    0a1516e4  45646165 6c45646e 6e656d65 6f540074  eadEndElement.To

    0a1516f4  33746e49 6d580032 6d614e6c 62615465  Int32.XmlNameTab

    0a151704  6700656c 4e5f7465 54656d61 656c6261  le.get_NameTable

    0a151714  64644100 6c6d7800 64616552 49007265  .Add.xmlReader.I

    0a151724  61745373 6c457472 6e656d65 626f0074  sStartElement.ob

    0a151734  7463656a 65536f54 6c616972 00657a69  jectToSerialize.

    0a151744  74697277 72007265 65646165 65730072  writer.reader.se

    0a151754  74495f74 74006d65 00657079 00500f00  t_Item.type...P.

    0:000> dc

    0a151764  006f0072 00750064 00740063 17000100  r.o.d.u.c.t.....

    0a151774  00720050 0064006f 00630075 004e0074  P.r.o.d.u.c.t.N.

    0a151784  006d0061 19000065 00680073 00700069  a.m.e...s.h.i.p.

    0a151794  00690070 0067006e 006e0049 006f0066  p.i.n.g.I.n.f.o.

    0a1517a4  00531900 00690068 00700070 006e0069  ..S.h.i.p.p.i.n.

    0a1517b4  00490067 0066006e 1700006f 00690044  g.I.n.f.o...D.i.

    0a1517c4  00740073 00690072 00750062 006f0074  s.t.r.i.b.u.t.o.

    0a1517d4  15000072 00610044 00730079 006f0054  r...D.a.y.s.T.o

    It looks like the type is Product

    Back to the stack

    0:018> kb

    ChildEBP RetAddr  Args to Child              

    02e2edc0 7c822124 77e6baa8 000005e0 00000000 ntdll!KiFastSystemCallRet [d:\srvrtm\base\ntos\rtl\i386\userdisp.asm @ 545]

    02e2edc4 77e6baa8 000005e0 00000000 02e2ee08 ntdll!NtWaitForSingleObject+0xc [d:\srvrtm\base\ntdll\daytona\obj\i386\usrstubs.asm @ 2371]

    02e2ee34 77e6ba12 000005e0 000927c0 00000000 kernel32!WaitForSingleObjectEx+0xac [d:\srvrtm\base\win32\client\synch.c @ 1246]

    02e2ee48 02e31b52 000005e0 000927c0 fcc43d98 kernel32!WaitForSingleObject+0x12 [d:\srvrtm\base\win32\client\synch.c @ 1147]

    02e2ee74 7a511af6 02e2ef20 00000228 03645ec0 CLRStub[StubLinkStub]@2e31b52

    02e2ef50 7a511414 00000000 00000000 00000000 System_ni!System.CodeDom.Compiler.Executor.ExecWaitWithCaptureUnimpersonated(Microsoft.Win32.SafeHandles.SafeUserTokenHandle, System.String, System.String, System.CodeDom.Compiler.TempFileCollection, System.String ByRef, System.String ByRef, System.String)+0x692

    02e2ef94 7a5334f6 00000000 00000000 00000000 System_ni!System.CodeDom.Compiler.Executor.ExecWaitWithCapture(Microsoft.Win32.SafeHandles.SafeUserTokenHandle, System.String, System.String, System.CodeDom.Compiler.TempFileCollection, System.String ByRef, System.String ByRef, System.String)+0x3c

    00000000 7a532abc 00000000 00000000 00000000 System_ni!Microsoft.CSharp.CSharpCodeGenerator.Compile(System.CodeDom.Compiler.CompilerParameters, System.String, System.String, System.String, System.String ByRef, Int32 ByRef, System.String)+0x1ca

    02e2f038 7a533cd7 00000000 00000000 00000000 System_ni!Microsoft.CSharp.CSharpCodeGenerator.FromFileBatch(System.CodeDom.Compiler.CompilerParameters, System.String[])+0x240

    02e2f090 7a532fd5 00000000 00000000 00000000 System_ni!Microsoft.CSharp.CSharpCodeGenerator.FromSourceBatch(System.CodeDom.Compiler.CompilerParameters, System.String[])+0x1b7

    02e2f0c4 7a4ae13e 00000000 00000000 00000000 System_ni!Microsoft.CSharp.CSharpCodeGenerator.System.CodeDom.Compiler.ICodeCompiler.CompileAssemblyFromSourceBatch(System.CodeDom.Compiler.CompilerParameters, System.String[])+0x29

    02e2f130 69d38122 00000000 00000000 00000000 System_ni!System.CodeDom.Compiler.CodeDomProvider.CompileAssemblyFromSource(System.CodeDom.Compiler.CompilerParameters, System.String[])+0x16

    02e2f130 69d36e75 00000000 00000000 00000000 System_Xml_ni!System.Xml.Serialization.Compiler.Compile(System.Reflection.Assembly, System.String, System.CodeDom.Compiler.CompilerParameters, System.Security.Policy.Evidence)+0x252

    02e2f1bc 69d35e11 00000000 00000000 00000000 System_Xml_ni!System.Xml.Serialization.TempAssembly.GenerateAssembly(System.Xml.Serialization.XmlMapping[], System.Type[], System.String, System.Security.Policy.Evidence, System.CodeDom.Compiler.CompilerParameters, System.Reflection.Assembly, System.Collections.Hashtable)+0x7e9

    03616ab4 69d9c288 00000000 00000000 00000000 System_Xml_ni!System.Xml.Serialization.TempAssembly..ctor(System.Xml.Serialization.XmlMapping[], System.Type[], System.String, System.String, System.Security.Policy.Evidence)+0x79

    03616ab4 69d9c16f 00000000 00000000 00000000 System_Xml_ni!System.Xml.Serialization.XmlSerializer.GenerateTempAssembly(System.Xml.Serialization.XmlMapping, System.Type, System.String, System.String, System.Security.Policy.Evidence)+0x60

    02e2f230 69d9bdcf 00000000 00000000 00000000 System_Xml_ni!System.Xml.Serialization.XmlSerializer..ctor(System.Type, System.Xml.Serialization.XmlAttributeOverrides, System.Type[], System.Xml.Serialization.XmlRootAttribute, System.String, System.String, System.Security.Policy.Evidence)+0xb3

    034736e8 0306303e 00000000 00000000 00000000 System_Xml_ni!System.Xml.Serialization.XmlSerializer..ctor(System.Type, System.Type[])+0x13

    034736e8 03062ec8 00000000 00000000 00000000 App_Code_gukcpxoe!DataLayer.GetProductInfo(System.String)+0x106

    03612a8c 698a1928 00000000 00000000 00000000 App_Web_eofj0z0s!ProductInfo.Page_Load(System.Object, System.EventArgs)+0x80

    I wanted to see that DataLayer.GetPRoductInfo is all about so saved the module

    0:018> lmvm App_Code_gukcpxoe

    start    end        module name

    02ff0000 02ffa000   App_Code_gukcpxoe C (no symbols)          

       Loaded symbol image file: App_Code.gukcpxoe.dll

       Image path: C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\Temporary ASP.NET Files\buggybits\0b50c844\fb864981\App_Code.gukcpxoe.dll

       Image name: App_Code.gukcpxoe.dll

       Using CLR debugging support for all symbols

       Has CLR image header, track-debug-data flag not set

       Timestamp:        Sat Mar 01 11:17:44 2008 (47C93B58)

       CheckSum:         00000000

       ImageSize:        0000A000

       File version:     0.0.0.0

       Product version:  0.0.0.0

       File flags:       0 (Mask 3F)

       File OS:          4 Unknown Win32

       File type:        2.0 Dll

       File date:        00000000.00000000

       Translations:     0000.04b0

       InternalName:     App_Code.gukcpxoe.dll

       OriginalFilename: App_Code.gukcpxoe.dll

       ProductVersion:   0.0.0.0

       FileVersion:      0.0.0.0

       FileDescription:  

       LegalCopyright:    

    0:018> !savemodule 02ff0000  c:\module.dll

    3 sections in file

    section 0 - VA=2000, VASize=2654, FileAddr=200, FileSize=2800

    section 1 - VA=6000, VASize=2c8, FileAddr=2a00, FileSize=400

    section 2 - VA=8000, VASize=c, FileAddr=2e00, FileSize=200

    After opening the module in Ludz Reflector

    public Product GetProductInfo(string ProductName)

    {

       Product o = new Product();

       ShippingInfo info = new ShippingInfo();

       o.ProductName = ProductName;

       info.Distributor = "Buggy Bits";

       info.DaysToShip = 5;

       o.shippingInfo = info;

       Type[] extraTypes = new Type[] { typeof(ShippingInfo) };

       MemoryStream stream = new MemoryStream();

       new XmlSerializer(typeof(Product), extraTypes).Serialize((Stream) stream, o);

       stream.Close();

       return o;

    }

    I see a call to XmlSerializer, typeof Product. Looks like i found the guilty one

    The XmlSerializer Leak is a known issue but just to be sure it was the correct

    ctor i looked inside XmlSerializer and found

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

    Along the way i did other stuff trying to get to the right spot. I noticed that

    no dlls were on hard drive so that means the they were loaded into memory. I dumped some objects

    and found this

    0:019> !do 0x035ef744

    Name: System.CodeDom.Compiler.CompilerParameters

    MethodTable: 7a75403c

    EEClass: 7a753f18

    Size: 56(0x38) bytes

    (C:\WINDOWS\assembly\GAC_MSIL\System\2.0.0.0__b77a5c561934e089\System.dll)

    Fields:

         MT    Field   Offset                 Type VT     Attr    Value Name

    7a74847c  4000f46        4 ....StringCollection  0 instance 035ef77c assemblyNames

    7a74847c  4000f47        8 ....StringCollection  0 instance 035ef7a0 embeddedResources

    7a74847c  4000f48        c ....StringCollection  0 instance 035ef7c4 linkedResources

    790fa3e0  4000f49       10        System.String  0 instance 036138cc outputName

    790fa3e0  4000f4a       14        System.String  0 instance 00000000 mainClass

    79104f64  4000f4b       30       System.Boolean  1 instance        1 generateInMemory

    79104f64  4000f4c       31       System.Boolean  1 instance        0 includeDebugInformation

    790fed1c  4000f4d       2c         System.Int32  1 instance       -1 warningLevel

    790fa3e0  4000f4e       18        System.String  0 instance 03610570 compilerOptions

    790fa3e0  4000f4f       1c        System.String  0 instance 00000000 win32Resource

    79104f64  4000f50       32       System.Boolean  1 instance        0 treatWarningsAsErrors

    79104f64  4000f51       33       System.Boolean  1 instance        0 generateExecutable

    7a754a14  4000f52       20 ...empFileCollection  0 instance 035ef7e8 tempFiles

    7a769078  4000f53       24 ...feUserTokenHandle  0 instance 00000000 userToken

    79109414  4000f54       28 ...y.Policy.Evidence  0 instance 00000000 evidence

    Does the generateInMemory==1 means this ? I mean from this i can infer that

    no dll will be on hard drive.

    One final question is:

    using the !heap -l to get possibly leaks would i be able to go anywhere ? Or is it only

    useful if i´m looking at a unmanaged dump ?

    In first dump

    029c7fa8  029c7fb0  029c0000  029c0000        40        40        1c  busy extra fill

    79e78360: mscorwks!EEHeapAlloc+0x12D

    79e7f00d: mscorwks!CExecutionEngine::ClrHeapAlloc+0x3C

    79ea55ef: mscorwks!Module::Initialize+0x8C

    79ea49dc: mscorwks!Module::DoInit+0xAE

    79ea4d79: mscorwks!Module::Create+0xF6

    79eb5879: mscorwks!Assembly::Init+0xD7

    79eb5767: mscorwks!Assembly::Create+0x120

    79eb47f6: mscorwks!DomainAssembly::Allocate+0x190

    79ea46b2: mscorwks!DomainFile::DoIncrementalLoad+0x63

    79e9f575: mscorwks!AppDomain::TryIncrementalLoad+0x97

    79e9f481: mscorwks!AppDomain::LoadDomainFile+0x19D

    79eabca0: mscorwks!AppDomain::LoadDomainAssembly+0x116

    79febbce: mscorwks!AppDomain::LoadAssembly+0x1A

    7a2cb616: mscorwks!AssemblyNative::GetPostPolicyAssembly+0x268

    565 potential unreachable blocks were detected.

    In second dump

    029cfe28  029cfe30  029c0000  029c0000        40        40        1c  busy extra fill

    79e78360: mscorwks!EEHeapAlloc+0x12D

    79e7f00d: mscorwks!CExecutionEngine::ClrHeapAlloc+0x3C

    79ea55ef: mscorwks!Module::Initialize+0x8C

    79ea49dc: mscorwks!Module::DoInit+0xAE

    79ea4d79: mscorwks!Module::Create+0xF6

    79eb5879: mscorwks!Assembly::Init+0xD7

    79eb5767: mscorwks!Assembly::Create+0x120

    79eb47f6: mscorwks!DomainAssembly::Allocate+0x190

    79ea46b2: mscorwks!DomainFile::DoIncrementalLoad+0x63

    79e9f575: mscorwks!AppDomain::TryIncrementalLoad+0x97

    79e9f481: mscorwks!AppDomain::LoadDomainFile+0x19D

    79eabca0: mscorwks!AppDomain::LoadDomainAssembly+0x116

    79febbce: mscorwks!AppDomain::LoadAssembly+0x1A

    7a2cb616: mscorwks!AssemblyNative::GetPostPolicyAssembly+0x268

    1497 potential unreachable blocks were detected.

  • AJAX ASP.NET AJAX In-Depth: Application Events [Via: swalther ] WPF WPF Wiimote Library (Now With Project...

  • excellent, wow first time the length of a comment exceeded the length of the post I think:D  

    yeah !heap -l would mostly be useful with native leaks

  • :) I only saw how big it was after posting it

    Is there any reason why the savemodule throws an exception ?

    0:000> lmvm ol2fh7hw

    (...)

    start    end        module name

    0a150000 0a152200   ol2fh7hw   (deferred)            

    0:000> !savemodule 0a150000 c:\d.dll

    3 sections in file

    section 0 - VA=2000, VASize=1894, FileAddr=200, FileSize=1a00

    section 1 - VA=4000, VASize=2a8, FileAddr=1c00, FileSize=400

    section 2 - VA=6000, VASize=c, FileAddr=2000, FileSize=200

    Fail to read memory

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