Archive for the ‘Garbage Collection’ Category

Justering af referencer i ubrugte objekter

Monday, July 5th, 2010

Dette indlæg omhandler forholdsvis eksotiske detaljer omkring implementeringen af garbage collection i .NET. Det vil næppe være relevant i ret mange tilfælde, men at kortlægge disse detaljer var en underholdende og lærerig øvelse, så dette indlæg er i realiteten mere et vidnesbyrd om, hvad vi kan lære om .NETs afviklingsmiljø ved hjælp af WinDbg og SOS.

En kollega kom for nogle dage siden forbi og spurgte, om jeg vidste noget om en funktion ved navn gc_heap::relocate_in_large_objects. Det gjorde jeg tilfældigvis, for jeg var selv stødt på denne lidt spøjst navngivne funktion i anden sammenhæng. Navnet kan jo få en til at tro, at objekter på Large Object Heap (LOH) bliver flyttet, hvilket jo som bekendt ikke er tilfældet. Funktionen står derimod for at justere referencer i objekter på LOH.

Betragt nedenstående figur.

LOH før garbage collection og compaction

Her har vi et array på LOH med referencer til objekter på den almindelige heap. Oprydning af sidstnævnte kan føre til at objekterne bliver rykket sammen for at forhindre fragmentering. Hvis dette sker, skal referencerne i vores array justeres, så de igen peger på de faktiske instanser. Efter en oprydning, sammenrykning og justering kan billedet se ud som følger:

LOH efter garbage collection og compaction

Det er der næppe noget nyt eller overraskende i, men min kollega synes at have observeret, at justering af referencer også skete, hvis den omtalte array ikke længere var i brug.

Kunne det være tilfældet?

Tænk lidt over det: Bliver referencer virkelig justeret for objekter, der ikke længere er i brug af applikationen?

Mit første svar var forkert. Jeg var overbevist om, at der ikke var nogen grund til at justere disse referencer i fald vores array ikke længere var i brug, men i stedet for at lade det komme an på, hvad jeg troede, satte jeg mig for at undersøge det.

Til formålet lavede jeg en lille testapplikation som angivet nedenfor:

sealed class SomeType {
   public int X { get; set; }
   public int Y { get; set; }

   public SomeType(int x, int y) {
      X = x;
      Y = y;
   }
}

sealed class Program {
   static void GenerateRandomObjects() {
      string s = null;
      for (int i = 0; i < 1000; i++) {
         s += i.ToString();
      }
      Console.WriteLine(s.Length);
   }

   static void Main() {
      Console.WriteLine("Press Enter to begin");
      Console.ReadLine();

      GenerateRandomObjects();
      var smallbuffer = new SomeType[100];
      var largebuffer = new SomeType[85000];

      for (int i = 0; i < smallbuffer.Length; i++) {
         var st = new SomeType(1, 2);
         smallbuffer[i] = st;
         largebuffer[i] = st;
      }

      Trace.WriteLine("Buffers filled");
      Debugger.Break();

      Trace.WriteLine(string.Format("smallbuffer is in gen{0}", GC.GetGeneration(smallbuffer)));

      Trace.WriteLine("Nulling root to largebuffer");
      largebuffer = new SomeType[200];
      Debugger.Break();

      Trace.WriteLine(string.Format("smallbuffer is in gen{0}", GC.GetGeneration(smallbuffer)));

      Trace.WriteLine("Collecting ...");
      GC.Collect(1);
      Trace.WriteLine(string.Format("smallbuffer is in gen{0}", GC.GetGeneration(smallbuffer)));
      GenerateRandomObjects();

      Trace.WriteLine("After GC");
      Debugger.Break();

      Console.WriteLine(smallbuffer.Length);
      Console.WriteLine(largebuffer.Length);
   }
}

Applikationen gør som følger:

  • Først opretter den et array, der er stort nok til, at det ryger på LOH.
  • Dette array sættes til at pege på et antal objekter allokeret på den almindelige heap. For at gøre det lettere at spore disse objekter, lader jeg også et mindre array referere disse.
  • Det næste skridt er, at sørge for at det store array ikke længere er refereret. Det er ikke helt så let, som det lyder. Det er ofte utilstrækkeligt at sætte den lokale reference til null. I mange tilfælde vil vi nemlig stadig have en gyldig reference på stakken eller i et register. Derfor er den bedste fremgangsmåde, at lade referencen pege på en ny instans. Det sikrer, at vi få overskrevet eventuelle gemte referencer.
  • Dernæst skal jeg iværksætte en garbage collection, der også laver compaction, så objekterne bliver flyttet på heapen. Dette er også mere tricky end som så, da vi ikke har mulighed for at angive, at der skal foretages compaction ved kald til GC.Collect(). Ergo, var jeg nødt til at prøve mig frem. Ved at lave en del tilfældige objekter rundt om mit lille array (og de refererede objekter) og derefter lave et kald til GC.Collect(1), fik jeg sat gang i den nødvendige oprydning. Så langt så godt.

For at undersøge om referencerne faktisk blev justeret i det store array, gjorde jeg følgende:

Ved første break brugte jeg !dumpheap til at finde mine arrays. Det mindste array har plads til 100 referencer, så jeg filtrerede listen, så jeg kun fik instanser på mere end 400 bytes.

0:004> g
Buffers filled
(1bdc.1918): Break instruction exception - code 80000003 (first chance)
eax=00000000 ebx=00000000 ecx=0000a020 edx=0030f230 esi=00687048 edi=00000064
eip=761d22a1 esp=0030f1a0 ebp=0030f23c iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
KERNELBASE!DebugBreak+0x2:
761d22a1 cc              int     3
0:000> !dumpheap -type Object[] -min 400
 Address       MT     Size
02427060 64cf6c28     8208
026dfc7c 64cf6c28      416
026f9758 64cf6c28      528
03421010 64cf6c28     4096
03422020 64cf6c28      528
03422240 64cf6c28     4096
03423250 64cf6c28     8176
03425250 64cf6c28   340016
total 0 objects
Statistics:
      MT    Count    TotalSize Class Name
64cf6c28        8       366064 System.Object[]
Total 8 objects

De to interessante instanser var henholdsvis 026dfc7c (smallbuffer) og 03425250 (largebuffer).

For at verificere, at de begge pegede på samme elementer, udskrev jeg første element i hver array.

Først smallbuffer:

0:000> !da -details -length 1 026dfc7c
Name:        LOHRoots.SomeType[]
MethodTable: 64cf6c28
EEClass:     64a79698
Size:        416(0x1a0) bytes
Array:       Rank 1, Number of elements 100, Type CLASS
Element Methodtable: 001638cc
[0] 026dfe1c
    Name:        LOHRoots.SomeType
    MethodTable: 001638cc
    EEClass:     001614e4
    Size:        16(0x10) bytes
    File:        C:\dev2010\LOHRoots\LOHRoots\bin\Release\LOHRoots.exe
    Fields:
              MT    Field   Offset                 Type VT     Attr    Value Name
        64d42978  4000001        4             System.Int32      1     instance            1     <X>k__BackingField
        64d42978  4000002        8             System.Int32      1     instance            2     <Y>k__BackingField

Og derefter largebuffer:

0:000> !da -details -length 1 03425250
Name:        LOHRoots.SomeType[]
MethodTable: 64cf6c28
EEClass:     64a79698
Size:        340016(0x53030) bytes
Array:       Rank 1, Number of elements 85000, Type CLASS
Element Methodtable: 001638cc
[0] 026dfe1c
    Name:        LOHRoots.SomeType
    MethodTable: 001638cc
    EEClass:     001614e4
    Size:        16(0x10) bytes
    File:        C:\dev2010\LOHRoots\LOHRoots\bin\Release\LOHRoots.exe
    Fields:
              MT    Field   Offset                 Type VT     Attr    Value Name
        64d42978  4000001        4             System.Int32      1     instance            1     <X>k__BackingField
        64d42978  4000002        8             System.Int32      1     instance            2     <Y>k__BackingField

Læg mærke til, at begge elementer peger på 026dfe1c. Så langt så godt.

Herefter kørte jeg videre til det punkt, hvor referencen til largebuffer overskrives:

0:000> g
smallbuffer is in gen0
Nulling root to largebuffer
(1bdc.1918): Break instruction exception - code 80000003 (first chance)
eax=00000000 ebx=00000000 ecx=0000a020 edx=0030f230 esi=00687048 edi=0242b3f8
eip=761d22a1 esp=0030f1a0 ebp=0030f23c iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
KERNELBASE!DebugBreak+0x2:
761d22a1 cc              int     3

Herefter verificerede jeg, at applikationen ikke længere havde roots til largebuffer.

0:000> !gcroot 03425250
Note: Roots found on stacks may be false positives. Run "!help gcroot" for
more info.
Scan Thread 0 OSTHread 1918
Scan Thread 2 OSTHread 1d34

Ingen roots, så den instans largebuffer peger på, kan ryddes op på dette tidspunkt. Videre til næste stop.

0:000> g
smallbuffer is in gen0
Collecting ...
smallbuffer is in gen1
After GC
(1bdc.1918): Break instruction exception - code 80000003 (first chance)
eax=00000000 ebx=00000000 ecx=0000a020 edx=0030f230 esi=00687048 edi=0242865c
eip=761d22a1 esp=0030f1a0 ebp=0030f23c iopl=0         nv up ei pl zr na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000246
KERNELBASE!DebugBreak+0x2:
761d22a1 cc              int     3

På dette tidspunkt har der netop været en garbage collection. Vi ved endnu ikke, om der også har været compaction. For at undersøge dette kan vi se, om vores arrays er blevet flyttet.

0:000> !dumpheap -type Object[] -min 400
 Address       MT     Size
0242566c 64cf6c28     8208
0242a3d0 64cf6c28      416
0243fb64 64cf6c28      816
03421010 64cf6c28     4096
03422020 64cf6c28      528
03422240 64cf6c28     4096
03423250 64cf6c28     8176
03425250 64cf6c28   340016
total 0 objects
Statistics:
      MT    Count    TotalSize Class Name
64cf6c28        8       366352 System.Object[]
Total 8 objects

Læg mærke til, at vores lille array er flyttet fra 026dfc7c til 0242a3d0, mens vores store array stadig befinder sig på 03425250. Der har altså været compaction i forbindelse med denne garbage collection.

Det interessante er således at finde ud af, om referencerne i vores store (og ubrugte) array er blevet justeret. Lad os se på det lille array:

0:000> !da -details -length 1 0242a3d0
Name:        LOHRoots.SomeType[]
MethodTable: 64cf6c28
EEClass:     64a79698
Size:        416(0x1a0) bytes
Array:       Rank 1, Number of elements 100, Type CLASS
Element Methodtable: 001638cc
[0] 0242a570
    Name:        LOHRoots.SomeType
    MethodTable: 001638cc
    EEClass:     001614e4
    Size:        16(0x10) bytes
    File:        C:\dev2010\LOHRoots\LOHRoots\bin\Release\LOHRoots.exe
    Fields:
              MT    Field   Offset                 Type VT     Attr    Value Name
        64d42978  4000001        4             System.Int32      1     instance            1     <X>k__BackingField
        64d42978  4000002        8             System.Int32      1     instance            2     <Y>k__BackingField

Og derefter det store:

0:000> !da -details -length 1 03425250
Name:        LOHRoots.SomeType[]
MethodTable: 64cf6c28
EEClass:     64a79698
Size:        340016(0x53030) bytes
Array:       Rank 1, Number of elements 85000, Type CLASS
Element Methodtable: 001638cc
[0] 0242a570
    Name:        LOHRoots.SomeType
    MethodTable: 001638cc
    EEClass:     001614e4
    Size:        16(0x10) bytes
    File:        C:\dev2010\LOHRoots\LOHRoots\bin\Release\LOHRoots.exe
    Fields:
              MT    Field   Offset                 Type VT     Attr    Value Name
        64d42978  4000001        4             System.Int32      1     instance            1     <X>k__BackingField
        64d42978  4000002        8             System.Int32      1     instance            2     <Y>k__BackingField

Læg mærke til at begge arrays peger på samme element. Referencen i det store array er således rettet fra 026dfe1c til 0242a570, og dermed kan vi konkludere, at det store array er blevet opdateret på trods af, at applikationen ikke længere har nogen gældende reference til dette array.

Hvordan kan det være?

Tænker vi lidt over, hvad der sker under en garbage collection, giver det faktisk god mening, men det er måske ikke så intuitivt ved første øjekast.

En garbage collection lægger ud med at lave en analyse af hvilke objekter på den aktuelle del af heapen, der stadig er i brug. Disse markeres som værende i brug. Alle andre objekter kan ryddes op. Nøgleordet her er den aktuelle del af heapen. I og med at testprogrammet kører en GC.Collect(1) foretages denne analyse således kun for objekter der ligger i generation 0 og 1. Vores store array ligger på LOH, og er således ikke berørt af denne analyse.

Da oprydningen også iværksætter en flytning af objekterne i dette tilfælde, er garbage collection-rutinen nødt til at opdatere referencerne til de flyttede objekter, men da den på dette tidspunkt ikke ved, at vores store array ikke længere er i brug, er den nødt til at opdatere disse referencer.

Disponeringen giver god mening, hvis analysen af aktive rødder er mere omfattende end justering af referencerne. Skønt det optimale ville være at springe opdateringen over, kan det sagtens give mening at udføre denne – i teorien – overflødige handling, hvis disse forhold er til stede. Den analyse har jeg svært ved at lave, men jeg har været i kontakt med en af de ansvarlige udviklere, og Microsoft kender til problematikken, og derfor har jeg tillid til, at de har lavet de nødvendige analyser og undersøgelser.

Ændrer vi testapplikationen så den kalder GC.Collect(2) i stedet (eller blot GC.Collect(), der ligeledes laver en komplet oprydning), laver garbage collection-rutinen en fuld analyse af heapen og finder således ud af, at det store array ikke længere er i brug. I det tilfælde opdateres referencerne naturligvis ikke, da den nødvendige viden er tilgængelig i dette tilfælde.

Som nævnt tror jeg ikke, at dette er et reelt problem i nogen væsentlig udstrækning. For at denne situation skal have indflydelse på afviklingen, skal applikationen have mange midlertidige objekter på LOH, disse skal i stor udstrækning referere objekter på den almindelige heap, og compaction skal foretages jævnligt. I det tilfælde vil man muligvis kunne spore en effekt, men det er i realiteten et afledt problem af at have mange midlertidige objekter på LOH. Det er af flere grunde en dårlig ide, og dette er således kun en af flere uheldige konsekvenser af den situation.

Hjælp til fejlsøgning af OutOfMemoryException

Thursday, February 18th, 2010

Da jeg kom tilbage fra forældreorlov, blev jeg involveret i at fejlsøge nogle OutOfMemoryExceptions, en af mine kolleger havde oplevet. Det var ikke så meget det, at der kom exceptions, men af en eller anden grund væltede disse exceptions hele afviklingsmiljøet. Vores .NET-kode afvikles i en CLR indlæst i en anden proces. Problemet var således, at disse exceptions rev værtsprocessen med sig i faldet. Det var ikke særlig hensigtsmæssigt.

Desværre var det relativt omfattende at reproducere fejlen, så derfor satte jeg mig for, at forsøge at genskabe problemet under lidt enklere forhold. Det er jo heldigvis ikke særlig svært, at fremprovokere en OutOfMemoryException, så jeg skulle bare finde en lille applikation i vores framework, som jeg kunne lade det gå ud over. Ikke længe efter kunne jeg således reproducere problemet, og så var det jo bare at finde ud af, hvorfor vores almindelige fejlhåndtering af en eller anden grund var sat ud af spil.

Jeg fyrede op under min applikation og koblede WinDbg på sagen. Hvor svært kunne det være. Desværre opførte applikationen sig eksemplarisk i selskab med WinDbg. Godt nok fik jeg en OutOfMemoryException som forventet, men vores fejlhåndtering virkede pludselig efter hensigten.

Min første tanke var således, at der var en eller anden sindrig race condition i fejlhåndteringen. En debugger ændrer som bekendt timingen i afviklingen, så det kunne jo være, at WinDbg introducerede den lille forskel, der var afgørende for om det virkede eller ej. Det måtte undersøges.

Jeg læste en masse kode igennem, men kunne ikke finde evidens for at der skulle være en race condition. Så debuggede jeg noget mere, forstyrrede et par kolleger, rev mig lidt i håret og var i det hele taget ikke just springfuld af ideer til, hvorfor pokker det opførte sig fint, så snart jeg pudsede WinDbg på problemet.

Efter at have spildt en rum tid med forskellige mindre undersøgelser, kastede jeg mig over Mario Hewardts seneste bog Advanced .NET Debugging. Den havde jeg læst lige inden, jeg gik på orlov, og jeg erindrede, at der vist var et afsnit om debugging af OutOfMemoryExceptions.

Bogen beskriver blandt andet en interessant registry setting, der kan bruges til hjælp af debugging af netop OutOfMemoryExceptions.

Sætter vi

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\.NETFramework\GCBreakOnOOM (DWORD)

til andet end 0, vil afviklingsmiljøet indskyde en break-instruktion i applikationen ved det første tegn på out of memory. Bogen beskriver godt nok flere værdier, men jeg kan kun konstatere at mulighederne er nul og ikke nul. Står nøglen til andet end nul, indskyder CLRen således et debug break, lige så snart den konstaterer out of memory.

Denne setting får altså afviklingsmiljøet til at opføre sig helt anderledes, og jeg havde ganske rigtigt pillet ved den, inden jeg gik på orlov og derefter glemt alt om det. Det forklarede, hvorfor problemet ikke forekom, når WinDbg var koblet på processen. I det tilfælde stoppede applikationen blot, og jeg kunne fortsætte, som om intet var hændt. Vores værtsproces havde det til gengæld ikke særlig godt med en umotiveret break-instruktion, og det var forklaringen på, hvorfor jeg kunne hive den ned med en OutOfMemoryException.

Men det forklarede jo ikke, hvorfor min kollega, der oprindelig havde rapporteret dette problem, så denne opførsel. Jeg blev dog nødt til at afklare, hvorvidt han eventuelt skulle have pillet ved denne eksotiske setting (en søgning giver ikke mange hits, så jeg regnede ikke med, at han var faldet over den ved et tilfælde, men jeg kunne jo lige så godt spørge). Til min overraskelse viste det sig, at han faktisk havde sat GCBreakOnOOM! Under min orlov havde han været forbi min plads og var faldet over Hewardts bog, som han havde lånt. Ved et tilfælde havde han læst om OutOfMemoryExceptions, set den omtalte setting, oprettet den i sit registry og derefter glemt alt om det.

Så hang tingene sammen igen, men hvad er chancerne for, at min kollega og jeg ikke alene begge sætter denne setting men også glemmer alt om det efterfølgende? Jeg er sikker på, at der er en relevant lektie et eller andet sted i denne oplevelse.

Lad mig afrunde dette indlæg med et par noter omkring GCBreakOnOOM.

Som nævnt får denne registry setting, afviklingsmiljøet til at opføre sig specielt i tilfældet af out of memory. Lige så snart CLRen opdager, at den skal til at smide en OutOfMemoryException, indskyder den en break-instruktion. Lad os se på et eksempel.

private static void Main(string[] args) {
    GenerateOOM();
}

private static void GenerateOOM() {
   var list = new List<double?>(10000000);
   while (true) {
       list.Add(0);
   }
}

Hvis vi kobler WinDbg på efter at have kørt ovenstående, vil vi således ikke se en exception, idet break-instruktionen indskydes inden afviklingsmiljøet smider OutOfMemoryException.

0:000> !threads
ThreadCount: 2
UnstartedThread: 0
BackgroundThread: 1
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
                                              PreEmptive                                                Lock
       ID OSID        ThreadOBJ     State   GC     GC Alloc Context                  Domain           Count APT Exception
   0    1  b60 0000000000c63350      a020 Enabled  0000000002941c70:0000000002943a60 0000000000c5a360     0 MTA
   2    2  fc4 0000000000c6b420      b220 Enabled  0000000000000000:0000000000000000 0000000000c5a360     0 MTA (Finalizer)

Ingen exception her. Lad os se på vores stak (bemærk desuden, at vi befinder os på den relevante tråd, da vi har indskudt en break-instruktion på denne).

0:000> !clrstack
OS Thread Id: 0xb60 (0)
Child-SP         RetAddr          Call Site
000000000028e710 000007ff00170336 System.Collections.Generic.List`1[[System.Nullable`1[[System.Double, mscorlib]], mscorlib]].set_Capacity(Int32)
000000000028e760 000007ff001701d2 System.Collections.Generic.List`1[[System.Nullable`1[[System.Double, mscorlib]], mscorlib]].Add(System.Nullable`1<Double>)
000000000028e7a0 000007ff00170129 TestBench.Program.GenerateOOM()
000000000028e800 000007feefa3d502 TestBench.Program.Main(System.String[])

Læg mærke til at set_Capacity ligger øverst på stakken, så det er altså den operation, vi er i gang med. set_Capacity er en hyppig årsag til out of memory. Det er nemlig her, at List<T>s underliggende array bliver udvidet med en ny af dobbelt størrelse, og derfor vil det ofte være den direkte årsag til out of memory. Lad os se om vores native stak giver yderligere detaljer.

0:000> k
Child-SP          RetAddr           Call Site
00000000`0028e338 000007fe`efc2dd33 KERNELBASE!DebugBreak+0x2
00000000`0028e340 000007fe`efc2dda3 mscorwks!`string'+0x55a93
00000000`0028e3b0 000007fe`ef916df3 mscorwks!`string'+0x55b03
00000000`0028e3e0 000007fe`efe65c79 mscorwks!AllocateArrayEx+0x323
00000000`0028e530 000007ff`00170437 mscorwks!JIT_NewArr1+0x239
00000000`0028e710 000007ff`00170336 0x7ff`00170437
00000000`0028e760 000007ff`001701d2 0x7ff`00170336
00000000`0028e7a0 000007ff`00170129 0x7ff`001701d2
00000000`0028e800 000007fe`efa3d502 0x7ff`00170129
00000000`0028e830 000007fe`ef8f9fd3 mscorwks!CallDescrWorker+0x82
00000000`0028e880 000007fe`ef90a3af mscorwks!CallDescrWorkerWithHandler+0xd3
00000000`0028e920 000007fe`ef87dc7f mscorwks!MethodDesc::CallDescr+0x24f
00000000`0028eb70 000007fe`ef861c74 mscorwks!ClassLoader::RunMain+0x22b
00000000`0028edd0 000007fe`ef899955 mscorwks!Assembly::ExecuteMainMethod+0xbc
00000000`0028f0c0 000007fe`ef9adb07 mscorwks!SystemDomain::ExecuteMainMethod+0x491
00000000`0028f690 000007fe`ef86855c mscorwks!ExecuteEXE+0x47
00000000`0028f6e0 000007fe`f3964989 mscorwks!CorExeMain+0xac
00000000`0028f740 000007fe`f3a05b21 mscoreei!CorExeMain+0x41
00000000`0028f770 00000000`7716f56d MSCOREE!CorExeMain_Exported+0x57
00000000`0028f7a0 00000000`772a3281 KERNEL32!BaseThreadInitThunk+0xd

Ej heller her er der spor af en exception, men vi kan se, at AllocateArrayEx bliver kaldt. Vi er med andre ord kommet ind før CLRen har kastet sin OutOfMemoryException. I debugging-terminologi er dette før first chance exception. Vi har altså alle muligheder for at inspicere tilstanden af applikationen inden the shit hits the fan så at sige.

Det vil også sige, at hvis vi kører videre, vil vi få den ventede exception.

0:000> g
(484.b60): C++ EH exception - code e06d7363 (first chance)
(484.b60): CLR exception - code e0434f4d (first chance)
(484.b60): CLR exception - code e0434f4d (!!! second chance !!!)
KERNELBASE!RaiseException+0x39:
000007fe`fd49aa7d 4881c4c8000000  add     rsp,0C8h

Bingo! Eftersom vi ikke gør noget for at fange exceptions, fortsætter koden med både first og second chance.

Herefter har vi vores exception, og debugging af problemet fra dette punkt svarer til det, vi ville se, hvis vi havde sat Adplus til at lave et crash dump.

0:000> !threads
ThreadCount: 2
UnstartedThread: 0
BackgroundThread: 1
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
                                              PreEmptive                                                Lock
       ID OSID        ThreadOBJ     State   GC     GC Alloc Context                  Domain           Count APT Exception
   0    1  b60 0000000000c63350      a020 Enabled  0000000002941e90:0000000002943a60 0000000000c5a360     0 MTA System.OutOfMemoryException (0000000002941c70)
   2    2  fc4 0000000000c6b420      b220 Enabled  0000000000000000:0000000000000000 0000000000c5a360     0 MTA (Finalizer)

Som forventet finder vi en OutOfMemoryException på vores hovedtråd:

0:000> !pe
Exception object: 0000000002941c70
Exception type: System.OutOfMemoryException
Message: <none>
InnerException: <none>
StackTrace (generated):
    SP               IP               Function
    000000000028E710 000007FF00170438 mscorlib_ni!System.Collections.Generic.List`1[[System.Nullable`1[[System.Double, mscorlib]], mscorlib]].set_Capacity(Int32)+0x48
    000000000028E760 000007FF00170337 mscorlib_ni!System.Collections.Generic.List`1[[System.Nullable`1[[System.Double, mscorlib]], mscorlib]].Add(System.Nullable`1<Double>)+0x27
    000000000028E7A0 000007FF001701D3 TestBench!TestBench.Program.GenerateOOM()+0x83
    000000000028E800 000007FF0017012A TestBench!TestBench.Program.Main(System.String[])+0xa

StackTraceString: <none>
HResult: 8007000e

Kigger vi på native stak, finder vi ligeledes de relevante kald i mscorwks og derefter kernelbase til håndtering af exceptions.

0:000> k
Child-SP          RetAddr           Call Site
00000000`0028e330 000007fe`ef8cf0bd KERNELBASE!RaiseException+0x39
00000000`0028e400 000007fe`efa1e38f mscorwks!RaiseTheExceptionInternalOnly+0x295
00000000`0028e4d0 000007fe`efe65cca mscorwks!UnwindAndContinueRethrowHelperAfterCatch+0x63
00000000`0028e530 000007ff`00170437 mscorwks!JIT_NewArr1+0x28a
00000000`0028e710 000007ff`00170336 0x7ff`00170437
00000000`0028e760 000007ff`001701d2 0x7ff`00170336
00000000`0028e7a0 000007ff`00170129 0x7ff`001701d2
00000000`0028e800 000007fe`efa3d502 0x7ff`00170129
00000000`0028e830 000007fe`ef8f9fd3 mscorwks!CallDescrWorker+0x82
00000000`0028e880 000007fe`ef90a3af mscorwks!CallDescrWorkerWithHandler+0xd3
00000000`0028e920 000007fe`ef87dc7f mscorwks!MethodDesc::CallDescr+0x24f
00000000`0028eb70 000007fe`ef861c74 mscorwks!ClassLoader::RunMain+0x22b
00000000`0028edd0 000007fe`ef899955 mscorwks!Assembly::ExecuteMainMethod+0xbc
00000000`0028f0c0 000007fe`ef9adb07 mscorwks!SystemDomain::ExecuteMainMethod+0x491
00000000`0028f690 000007fe`ef86855c mscorwks!ExecuteEXE+0x47
00000000`0028f6e0 000007fe`f3964989 mscorwks!CorExeMain+0xac
00000000`0028f740 000007fe`f3a05b21 mscoreei!CorExeMain+0x41
00000000`0028f770 00000000`7716f56d MSCOREE!CorExeMain_Exported+0x57
00000000`0028f7a0 00000000`772a3281 KERNEL32!BaseThreadInitThunk+0xd
00000000`0028f7d0 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

Endnu et managed memory leak

Monday, March 23rd, 2009

Mens jeg var til MVP summit i Seattle, sloges nogle kolleger med, hvad der så ud til at være et memory leak i Oracles data provider til .NET. Jeg fik fornøjelsen af opgaven, da jeg kom hjem.

Mine kolleger havde allerede lavet en god del af arbejdet med at finde årsagen til problemet. De havde fundet et scenarie, der konsekvent kunne reproducere fejlen, de havde fundet en relevant fejlrapport om problemet hos Oracle, og de havde tilmed identificeret hvilken type, der så ud til at være årsagen til problemet. Opgaven bestod derfor i at finde ud af, hvorfor instanser af den pågældende type ikke blevet ryddet op som forventet. 

Af fejlrapporten hos Oracle fremgik det, at problemet kunne omgås ved kald af både GC.Collect() og GC.WaitForPendingFinalizers(). Det er selvfølgelig belejligt, at der er et workaround, men det var selv ikke efter Oracles mening en god løsning. Det kunne jeg kun give dem ret. 

Hvor er hullet?

Jeg lagde ud med at verificere, at leaket var relateret til den type, mine kolleger havde fundet frem til. Det første skridt var derfor at inspicere heapen. Typisk vil synderen være blandt topscorerne af antal allokerede objekter. Som kollegerne allerede havde konstateret, var det en intern Oracle-type ved navn OpoDecCtx, der var årsagen til problemerne. 

For at finde ud af hvad, der holdt disse i live, tog jeg et par tilfældige instanser fra heapen og brugte !gcroot til at give mig en liste af roots for disse objekter. Det viste sig, at det var finalizer-køen, der var synderen. Det kunne tyde på, at finalizer-tråden blokerede af en eller anden grund. En blokeret finalizer-tråd forhindrer indsamling af alle de objekter, der venter på at få kørt deres finalizers, så det kan sagtens være årsagen til et memory leak. 

Blokeret finalizer

Mit næste skridt var derfor at se, hvad finalizer-tråden lavede. Til min overraskelse havde den ingen managed kaldestak. Det undrede mig lidt, og jeg var ikke helt klar over, hvad årsagen til dette kunne være. Heldigvis kunne jeg dog stadig se en native stak for tråden. Af den fremgik det, at tråden ventede. Det havde jeg egentlig også regnet med, så nu var det blot at finde ud af, hvad tråden ventede på. 

Via argumentet til ntdll!ZwWaitForSingleObject() kunne jeg lokalisere det handle, tråden ventede på, og via !handle, kunne jeg se, at der var tale om en event. Desværre er events ikke ejet af en specifik tråd, så det er, så vidt jeg ved, ikke umiddelbart mulig at finde ud af, hvilken anden tråd, finalizer-tråden ventede på. Det var således lidt af en blindgyde.

I mangel på bedre fyrede jeg derfor op for Reflector for at se lidt nærmere på OpoDecCtx. Typen implementerer IDisposable og en Dispose()-metode, der rydder op som forventet. Den har også en finalizer, der fungerer som bagstopper ved at kalde Dispose().

Typen bruges af et hav af andre Oracle-typer og mine stikprøver viste, at ingen af disse kalder Dispose(). Ergo er oprydning i de tilfælde afhængig af OpoDecCtxs finalizer. Det er måske ikke optimalt, men det burde fungere. 

Teorier

På det tidspunkt havde jeg to teorier, der begge havde sine svagheder. Hvis finalizeren faktisk var blokeret, forklarede det naturligvis, hvorfor instanserne ikke blev ryddet op, men det kunne ikke forklare, hvorfor det hjalp at kalde GC.WaitForPendingFinalizers() som Oracle foreslog. Hvis finalizer-tråden var blokeret, ville et kald til WaitForPendingFinalizers() blot medføre at den kaldende tråd blokerede. 

Min anden teori var, at instanser blev oprettet hurtigere end finalizeren kunne nå at behandle dem. Det ville forklare hvorfor leaket forsvandt, hvis vi blot ventede på finalizeren. Denne situation er faktisk mulig, men ikke særlig sandsynlig. Finalizer-tråden kører med højere prioritet end normale tråde, men kombinationen af mange, hurtige allokeringer og lidt for langsome finalizers kan bringe finalizer-tråden i knæ. Situationen bliver kun værre, hvis der er mange tråde i spil. Problemet var bare, at det ikke helt stemte med hverken vores brugsmønster eller den kode, jeg havde set på ved hjælp af Reflector.

Samlet køretid: Ingen

For at undersøge om der faktisk var tale om et kapløb mellem allokering og oprydning, besluttede jeg mig for at se nærmere på, hvor lang tid de enkelte tråde i applikationen havde kørt. !runaway-kommandoen giver det fornødne overblik. Det viste lidt overraskende, at finalizer-tråden slet ikke havde fået tildelt køretid, til trods for at programmet havde kørt i længere tid. !finalizequeue rapporterede desuden, at der var et meget højt antal objekter, der ventede på at få kørt deres finalizer. 

Det aflivede definitivt den teori, men det efterlod mig med spørgsmålet om, hvorfor finalizer-tråden slet ikke kom i gang. 

Tilbage til stakken

Nu er det selvfølgelig altid let, at beskrive hvordan nålen adskiller sig fra stråene i høstakken, når man først har fundet nålen, men det tog altså et par afstikkere, før jeg kom tilbage til finalizerens native stak, der viste sig at rumme det afgørende spor. 

Jeg var nødt til at finde ud af, hvad finalizer-tråden lavede – eller rettere sagt ikke lavede. Min erfaring med low level Windows-programmering er begrænset, så mange af kaldene i en native stak, giver kun begrænset mening for mit vedkommende. Der var dog et kald, der sprang i øjnene – et kald til GetToSTA().

Finalizer-tråden forsøgte altså at skubbe sit arbejde videre til hovedtråden, der som den eneste kørte i en Single Threaded Appartment (STA). Mekanismen ligner det, vi kender fra GUI-progammering, hvor vi også bliver nødt til at bede GUI-tråden udføre alle opdateringer på de enkelte GUI-komponenter. Denne kommunikation er implementeret via Windows-beskeder, så det kræver naturligvis, at STA-tråden behandler disse. 

Havde der været tale om en GUI-tråd, ville alt derfor have spillet som forventet. Desværre var denne del af koden lavet som en kommandolinjeapplikation, og de har desværre den uheldige egenskab, at de ikke umiddelbart håndterer Windows-beskeder. Eftersom at finalizer-tråden således forsøgte at afsætte sine opgaver til hovedtråden, der prompte ignorerede forespørgslerne, endte vi med et memory leak. Finalizerne blev ikke kørt, fordi finalizer-tråden ikke kunne komme af med sit arbejde til hovedtråden. 

Mulige løsninger

Som nævnt var Oracles workaround at kalde GC.Collect() og GC.WaitForPendingFinalizers(), men hvorfor skulle det have en effekt? Det er i hvert fald ikke indlysende. Som nævnt ville den oplagte effekt af at vente på en blokeret tråd være endnu en blokering.

Forklaringen skal findes i implementeringen af CLRen. For at afskærme .NET-udviklere for de ubehagelige detaljer ved en del af Windows’ ret kringlede messaging-model, står CLRen nærmest på hovedet for at gøre så meget af det nødvendige low level-arbejde som mulig. Således sørger CLRen selv for at håndtere beskeder som en del af forskellige andre opgaver. Blandt andet behandler CLRen beskeder i forbindelse med kald til WaitForPendingFinalizers(). Det vil altså sige, at Oracles løsning fungerede fordi, der som en bivirkning af kaldet til WaitForPendingFinalizers() bliver behandlet beskeder.

Med denne viden i bagagen var det ikke svært at grave yderligere information frem, og der viste sig faktisk at være en knowledge base-artikel, der beskrev et relateret problem, og heri kunne jeg læse, at Join() ligeledes resulterer i at der bliver behandlet beskeder. En lidt mere elegant workaround er således at kalde

Thread.CurrentThread.Join(0);

Det blokerer den kørende tråd, indtil den er færdig, eller indtil timeout indtræffer (hvilket naturligvis vil sige, at den altid blokerer, indtil timeout indtræffer). Selv med en værdi på 0 ms er det nok, til at lade finalizer-tråden komme til, men afhængig af omstændighederne, kan det være nødvendig at benytte en længere timeout. 

En sidste løsning er naturligvis, at flytte den kaldende tråd fra STA til MTA, da det fjerner problemet med at flytte finalizer-trådens opgaver. Der kan dog være andre grunde til, at dette ikke umiddelbart er muligt. 

Ovenstående illustrerer nogle af de faldgruber den nuværende implementering af finalizer-mekanismen desværre lider under. Jeg ved, at det har været på tale at ændre implementeringen, så finalizers afvikles af threadpool tråde, men det er sikkert heller ikke uden sine uhensigtsmæssigheder i visse situationer, så vi må se, hvad det ender med. 

Introduktion til AppDomains – tredje del

Monday, May 19th, 2008

I de to første indlæg (her og her), har vi set på motivationen for AppDomains samt hvad der i praksis skal til for at få dem i luften. I dette indlæg vil jeg se på nogle af de specielle omstændigheder, der gør sig gældende, når vi arbejder med AppDomains.

Lad os lægge ud med at se lidt på hvordan AppDomains ser ud i afviklingsmiljøet. Til formålet bruger vi en opdateret udgave af det simple eksempel fra forrige indlæg. I sin helhed ser det ud som følger:

namespace SimpleAppDomain {
   class Program {
      static void Main(string[] args) {
         SomeType st = new SomeType("Main");
         Console.WriteLine("In Main with SomeType created in '{0}'", st.CreatedIn);
         AppDomain domain = AppDomain.CreateDomain("New AppDomain");
         domain.DoCallBack(Hello);
         Console.WriteLine("Press <Enter>");
         Console.ReadLine();
         AppDomain.Unload(domain);
      }

      static void Hello() {
         SomeType st = new SomeType("Hello");
         Console.WriteLine("Hello from '{0}'", AppDomain.CurrentDomain.FriendlyName);
         Console.WriteLine("SomeType created in '{0}'", st.CreatedIn);
      }
   }

   class SomeType {
      public SomeType(string createdin) {
         CreatedIn = createdin;
      }

      public readonly string CreatedIn;
   }
}

Hvis vi kører ovenstående og kobler WinDbg på, kan vi inspicere applikationens afviklingsmiljø, som det ser ud ved ReadLine(). Den noget umotiverede brug af SomeType skyldes, at vi har brug for et par let identificerbare instanser på heapen, så vi har noget at se på i WinDbg, når vi skal se på, hvordan AppDomains anvender heapen.

Det første, vi kan gøre, er at se hvilke AppDomains, vi har i spil. !DumpDomain lister AppDomains for den aktuelle proces.

0:007> !dumpdomain
--------------------------------------
System Domain: 7a3bc8b8
LowFrequencyHeap: 7a3bc8dc
HighFrequencyHeap: 7a3bc934
StubHeap: 7a3bc98c
Stage: OPEN
Name: None
--------------------------------------
Shared Domain: 7a3bc560
LowFrequencyHeap: 7a3bc584
HighFrequencyHeap: 7a3bc5dc
StubHeap: 7a3bc634
Stage: OPEN
Name: None
Assembly: 001aa628
--------------------------------------
Domain 1: 00163240
LowFrequencyHeap: 00163264
HighFrequencyHeap: 001632bc
StubHeap: 00163314
Stage: OPEN
SecurityDescriptor: 00159f38
Name: SimpleAppDomain.exe
Assembly: 001aa628 [C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll]
ClassLoader: 001aa6b0
SecurityDescriptor: 0019d848
  Module Name
790c2000 C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll
009923dc C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\sortkey.nlp
00992050 C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\sorttbls.nlp

Assembly: 001b3e80 [c:\workspaces\AppDomains\SimpleAppDomain\bin\Release\SimpleAppDomain.exe]
ClassLoader: 001b3ae8
SecurityDescriptor: 001af0d0
  Module Name
00972c3c c:\workspaces\AppDomains\SimpleAppDomain\bin\Release\SimpleAppDomain.exe

--------------------------------------
Domain 2: 001bc9e0
LowFrequencyHeap: 001bca04
HighFrequencyHeap: 001bca5c
StubHeap: 001bcab4
Stage: OPEN
SecurityDescriptor: 001bea80
Name: New AppDomain
Assembly: 001aa628 [C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll]
ClassLoader: 001aa6b0
SecurityDescriptor: 001b9148
  Module Name
790c2000 C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll
009923dc C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\sortkey.nlp
00992050 C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\sorttbls.nlp

Assembly: 001d0050 [c:\workspaces\AppDomains\SimpleAppDomain\bin\Release\SimpleAppDomain.exe]
ClassLoader: 001d00d8
SecurityDescriptor: 001cff28
  Module Name
010f2d60 c:\workspaces\AppDomains\SimpleAppDomain\bin\Release\SimpleAppDomain.exe

Læg mærke til, at vi faktisk har fire AppDomains; vores applikation (Domain 1), vores ekstra AppDomain (Domain 2) samt de to system-AppDomains, System Domain og Shared Domain, jeg omtalte i første indlæg. Jeg vil ikke gå i detalje med disse i dette indlæg, men kort fortalt står System Domain for opstart af hele processen. Det vil sige, at den blandt andet indlæser mscorlib i Shared Domain. Derudover er det også i System Domain, at interned strenge opbevares. Shared Domain bruges som navnet antyder til opbevaring af assemblies, der deles mellem forskellige AppDomains. Det vil f.eks. sige alle de basale typer defineret i mscorlib.

Det næste, vi kan gøre, er at kaste et blik på heapen. Det kan vi gøre med !DumpHeap, og for at begrænse output, sætter jeg den til at filtrere på typer, hvis navn indeholder navnet på vores namespace. Det giver følgende:

0:007> !dumpheap -stat -type SimpleAppDomain
total 2 objects
Statistics:
      MT    Count    TotalSize Class Name
010f31ec        1           12 SimpleAppDomain.SomeType
009730c4        1           12 SimpleAppDomain.SomeType
Total 2 objects

Som det fremgår ligger såvel Mains som Hellos instanser af SomeType på heapen, hvilket skyldes, at samtlige AppDomains deler den samme heap. Det lyder måske lidt underligt i forhold til ideen om at AppDomains bruges til at isolere de enkelte delapplikationer fra hinanden, men eftersom managed code ikke har mulighed for at manipulere heapen direkte, er dette helt forsvarligt.

Garbage collection på tværs af AppDomains er dog ikke uden sine udfordringer. Som vi allerede har set på, vil eventuelt delte objekter typisk være baseret på MarshalByRefObject, hvilket vil sige, at det ene AppDomain har en reference til en proxy. Det andet AppDomain vil i mange tilfælde kun have en intern reference til instansen i form af en reference fra det kode, der sørger for at håndtere marshalling mellem de to AppDomains. Hvordan skal denne kode vide, hvornår proxyen ikke længere er i spil? Det ved den heller ikke, og i stedet bruges en timer, en såkaldt lease.

I praksis fungerer det ved, at denne timer holder øje med brugen af det objekt, proxyen repræsenterer. Hver gang dette tilgås, nulstilles timeren og forlænger dermed levetiden af objektet. Hvis timeren overskrider en grænseværdi (som default ca. 5 minutter), antager koden, at proxyen ikke længere er i spil og frigiver herefter referencen, så instansen kan blive ryddet op af garbage collectoren.

Det er naturligvis muligt at justere grænseværdien efter behov. MarshalByRefObject definerer en virtuel metode InitializeLifetimeService, der returnerer et lease-objekt. For at ændre grænseværdien, skal vores type blot overstyre denne metode til at returnere en lease med den ønskede værdi. Hvis vi helt vil frakoble denne mekanisme og dermed selv tage ansvaret for, at instanserne bliver ryddet op, skal vi blot returnerer null.

Men hvordan sørger vi for, at et objekt bliver ryddet op i en managed applikation? Vores eneste indflydelse på oprydningen er at kalde GC.Collect(), men det igangsætter blot en oprydning. Hvis vores instans stadig er refereret – og det er den jo i dette tilfælde – gør det ingen verdens forskel. Så hvordan kommer vi af med disse udødelige instanser?

Svaret er, at alle instanser naturligvis kan opryddes, når AppDomainet ikke længere refererer dem. Ergo, bliver disse instanser først fjernet fra heapen, når vi nedlægger vores AppDomain, hvilket vi som illustreret tidligere kan gøre med AppDomain.Unload().

Så for at afrunde dette indlæg på passende vis, kan vi se på, hvad der sker, når vi nedlægger et AppDomain. Det åbenlyse er naturligvis at AppDomainet og alle dets lokale assemblies frigives. Det knap så indlysende er, at vi også risikerer at miste et antal tråde ved samme lejlighed. Når et AppDomain unloades, inspiceres kaldestakken for samtlige managed tråde og hvis en eller flere af disse har returadresse i det AppDomain, der nedlægges, indskydes en ThreadAbortException på de pågældende tråde. En ThreadAbortException kan fanges, men CLRen sørger selv for at smide den igen, så i praksis betyder det, at disse tråde vil blive nedlagt.

Fordelen ved dette er naturligvis at vi ikke risikerer, at en tråd pludselig hopper tilbage i det nu nedlagte AppDomain, men er man ikke klar over denne opførsel, kan det naturligvis komme som lidt af en overraskelse. Derfor er det vigtig, at vi har styr på hvilke tråde, der afvikler kode i specifikke AppDomains. Har vi det, er problemet ikke så stort endda.

Der er stadig flere detaljer, vi ikke har gennemgået, men jeg håber, at denne lille serie ikke desto mindre har givet en brugbar introduktion til AppDomains i C#.

Når exceptions bliver væk

Friday, March 28th, 2008

I den klassiske More Effective C++ diskuterer Scott Meyers et væld af komplikationer ved exceptions i C++. Et af emnerne drejer sig om, hvad der sker, hvis der bliver smidt en exception under behandlingen af en exception. Inspireret af Meyers’ mange overvejelser, tænkte jeg, at det kunne være interessant at se på nogle af detaljerne omkring exceptions i C#.

I denne sammenhæng er using-konstruktionen bemærkelsesværdig, da den jo som bekendt genererer kode, der svarer til en try/finally-block. Så hvad sker der, hvis både koden i try og finally smider en exception?

Betragt nedenstående klasse, der illustrerer problemet. SomeType implementerer IDisposable og har derfor en Dispose()-metode. Desværre smider Dispose() en ExceptionInDispose exception, og Foo() smider en ExceptionInMethod exception.

public class SomeType : IDisposable {
   public void Dispose() {
      throw new ExceptionInDispose();
   }

   public void Foo() {
      throw new ExceptionInMethod();
   }
}

public class ExceptionInDispose : Exception { }
public class ExceptionInMethod : Exception { }

Hvis vi bruger vores type i en using-blok, vil Dispose() blive kaldt ved udgangen af using-blokken, og spørgsmålet er nu: Hvilken exception fanges af vores catch-blok?

try {
   using (SomeType st = new SomeType()) {
      st.Foo();
   }
} catch (Exception e) {
   Console.WriteLine(e);
}

Svaret er, at catch-blokken fanger en ExceptionInDispose, og der er ingen spor af den oprindelige ExceptionInMethod. Den ligger ikke som InnerException, og hvis vi har sat Visual Studio til at stoppe på unhandled exceptions, sker der heller ikke noget, når vi kører ovenstående. Vores oprindelige exception er for alle praktiske formål væk. (Visual Studio giver os dog lov at reagere, hvis vi sætter debuggeren til at stoppe ved thrown exception).

using genererer som bekendt kode svarende til nedenstående:

SomeType st = new SomeType();
try {
   st.Foo();
} finally {
   if (st != null)
      st.Dispose();
}

og problemet er således, at hvis vi smider en exception i finally-delen, mister vi den oprindelige exception. finally bliver kørt, uanset om der er en exception eller ej, og alle indlejrede finally-blokke bliver afviklet inden en omsluttende catch-blok.

Specifikationen for C# er da også meget præcis på dette punkt. Hvis en exception undslipper en finally-blok, vil en eventuel eksisterende exception blive tabt som illustreret ovenfor.

Problemet er, at using ikke giver os mulighed for at definere en catch-blok, og vi kan heller ikke påvirke den genererede finally-blok. Har vi brug for at kunne reagere på ExceptionInMethod, er vi derfor nødt til at udskifte using-blokken med en try/catch/finally-blok som vist nedenfor.

try {
   SomeType st = new SomeType();
   try {
      st.Foo();
   } catch (Exception e) {
      Console.WriteLine(e);
   } finally {
      if (st != null)
         st.Dispose();
   }
} catch (Exception e) {
   Console.WriteLine(e);
}

I det tilfælde kan vi få lov at reagere på begge exceptions.

Med andre ord: hvis der er en risiko for, at Dispose() kan smide en exception, er using ikke særlig anvendelig, idet eventuelle fejl fra try-bloken vil blive tabt i tilfælde af en exception fra Dispose().

Det var en fejl

Friday, February 15th, 2008

For knap et år siden beskrev jeg, hvordan instanser af Control-klassen ikke blev ryddet ordentlig op. Jeg konkluderede, at den opførsel, vi kunne konstatere ved et lille testprogram og en tur i WinDbg, gav anledning til en del undren, men jeg kunne ikke forklare, hvorfor det forholdt sig som tilfældet var.

På det tidspunkt var jeg tilbageholdende med at kalde fænomenet for en fejl, og det var min antagelse, at i praksis ville det ikke betyde det store, eftersom at oprydningen faktisk blev udført, hvis vi blot huskede at kalde CreateControl() på instansen. WinForms er ret funky, og der foregår en masse bag facaden, så min antagelse var, at det nok var mere sandsynligt, at der skulle være et eller andet jeg havde overset, end at der faktisk skulle være en fejl i noget så basalt som Control-klassen. På det tidspunkt var min teori, at problemet var relateret til brugen af CreateControl() og Dispose(). Min ide var, at Controls (eller rettere baseklassen Component) fik en eller anden speciel behandling af CLRen.

Jeg tog fejl. Ser vi listen af rettelser i Service Pack 1 til .NET Framework 2.0 igennem, finder vi nemlig følgende: FIX: A memory leak may occur when you create and then delete Windows form control objects in an application that is built on the .NET Framework 2.0. Der var altså blot tale om en banal fejl. Opretter man instanser af Control, bliver de ikke ryddet op. Jeg kunne altså have påpeget problemet helt uden at se på Dispose() og CreateControl(). Jeg kan dog stadig ikke forklare, hvorfor jeg kunne konstatere, at et kald til CreateControl() kunne gøre en forskel, men det forhold har sikkert være årsag til at fejlen ikke har skabt større opmærksomhed.

Finalizers skal være effektive

Monday, January 21st, 2008

Under frokosten forleden dag sagde en kollega, at han godt kan lide finalizers, for de giver en sikkerhed for, at der bliver ryddet op. Jeg har allerede beskrevet to tilfælde, hvor denne antagelse ikke holder, og i dette indlæg vil jeg se på endnu en situation, hvor finalizers ikke bliver afviklet som forventet.

Når CLRen lukker en proces iværksættes en afvikling af finalizers. Det vil sige, at finalize-tråden vækkes og sættes til at kalde finalizers for tilbageværende, relevante instanser. Under normale omstændigheder må en finalizer køre lige så længe, det skal være. Det er en rigtig dårlig ide, eftersom finalizers afvikles sekventielt, men ellers er der ikke noget, der forhindrer dette.

Under nedlukning af processen er CLRen knap så tålmodig. Faktisk får hver finalizer maksimalt ca. 2 sekunder til at køre færdig, og samtlige finalizers skal være afviklet i løbet af ca. 40 sekunder (det er grænseværdierne på nuværende tidspunkt, men Microsoft kan selvfølgelig justere dem efter forgodtbefindende, så lad være med at basere kode på disse værdier). Overholdes disse krav ikke, slår CLRen finalize-tråden ned og lukker processen uden yderligere afvikling af finalizers. Ergo kan en enkelt langsom finalizer være årsag til at flere eller i værste fald alle finalizers bliver sprunget over i forbindelse med nedlukning af processen.

Det er let at påvise CLRens opførsel på dette punkt. Nedenstående eksempel illustrerer situationen via en finalizer, der aktivt bruger lidt over 2 sekunder på at blive færdig.

class Program {
   static void Main(string[] args) {
      WithFinalizer wf = new WithFinalizer();
      Console.WriteLine("in main");
   }
}

public class WithFinalizer {
   ~WithFinalizer() {
      Console.WriteLine("in finalizer");
      Spin(2500);
      Console.WriteLine("done finalizing");
   }

   public static void Spin(int milliseconds) {
      for (int stop = Environment.TickCount + milliseconds; Environment.TickCount < stop; ) ;
   }
}

Kører vi ovenstående kode, udskrives beskeden done finalizing aldrig, for CLRen lukker og slukker, inden vi når så langt.

Et spin-loop som dette repræsenterer intensivt CPU-arbejde. I dette tilfælde i lidt over 2 sekunder. Det er meget voldsomt, og forhåbentlig er der ingen, der kunne finde på at lave en finalizer med den opførsel, men læg mærke til at CLRens utålmodighed går på tid, og ikke på hvor meget finalizeren skal udføre. Så hvis en af vores finalizers f.eks. blokerer i ca. 2 sekunder, har vi samme problem, hvilket vi let kan eftervise ved at udskifte vores spin-loop med lidt over 2 sekunders blokering.

~WithFinalizer() {
   Console.WriteLine("in finalizer");
   Thread.Sleep(2500);
   Console.WriteLine("done finalizing");
}

Også her bliver CLRen træt af at vente, og slår processen ned uden at køre vores finalizer til ende. Der er jo forhåbentlig heller ikke nogen, der kunne finde på at kalde Sleep() i en finalizer, men jeg er helt sikker på, at der nok skal være nogen derude, der har leget med tanken om at skrive til en log fra en finalizer, og det er vel næppe helt utænkeligt, at de kunne finde på at skrive til en fil. Hvis disken eller måske endda filserveren, hvis der er sådan en i spil, er i knæ, kan den slags tage tid og i værste fald så lang tid, at CLRen anser det som et problem og gør noget ved det.

Jeg skal være den første til at indrømme, at disse problemer nok ikke optræder så tit endda, men de hyppige faldgruber er jo netop dem, vi lærer at undgå. Det er de eksotiske problemer, der har det med at udvikle sig til skingre supportsager med efterfølgende overarbejde til følge, og derfor er det godt at kende lidt til de forskellige risici og omstændighederne for dem.

Den bedste måde at undgå problemer med finalizers er at bruge dem meget spartansk og under ingen omstændigheder forsøge at udføre operationer, der kan fejle eller tage lang tid.