OutOfMemoryException и как его побороть

Думаю, многие разработчики в своей практике сталкивались с такой неприятной исключительной ситуацией, как OutOfMemoryException. Чем она неприятна? Тем, что она свидетельствует об одной из двух вещей: либо ваше приложение скушало всю доступную память и сделало это ожидаемо, потому что вы его так запрограммировали, либо оно сделало это вследствие утечки памяти (memory leak). И первый, и второй случай чреваты серьезными проблемами. В первом случае нам нужно рефакторить код и, возможно, даже архитектуру с целью избежания этой ситуации в дальнейшем, и не факт, что при этом не придется придумывать какие-нибудь обходные методы. Во втором случае мы сталкиваемся с тем, что мы, скорее всего, понятия не имеем, где происходит утечка и как с этим бороться, то есть у нас налицо предстоящий достаточно сложный дебаг. И самое неприятное во всей этой ситуации то, что мы не знаем, с каким же все-таки вариантом мы имеет дело. А если не знаем, значит, самое время взять скальпель стетоскоп и прослушать пациента.

Для начала нужно разобраться с тем, как приложения (в нашем случае, веб-приложения) работают с памятью в Windows. Я думаю, многие замечали, что очень часто проблемы с OutOfMemoryException начинаются еще когда приложение только-только вышло за рубеж 1 Гб. Но ведь мы работаем в 32-битной системе, значит приложение может адресовать до 4 Гб памяти, не так ли? Не совсем. Дело в том, что из этих 4 Гб половину забирает себе Windows, а остальное делится между исполняющей средой .NET Framework и нашим приложением. Вот и получается, что памяти у нашего приложения не так уж и много. Заинтересовавшихся отсылаю за деталями к хорошей статье некоего Jesper’а, отличной ресторанной аналогии Tess и статье Johan Straarup.

Итак, попробуем разобраться, что же происходит внутри нашего приложения

Первый шаг очень простой: необходимо собрать как можно больше информации. Для начала общаемся с QA, которые нашли баг и пытаемся выяснить условия, при которых воспроизводится баг. OutOfMemoryException – исключение подлое, в большинстве случаев оно не воспроизводится в лоб, а просто вылетает в какой-то момент жизни приложения, когда память переполнится. Полученная информация нам поможет и для воспроизведения бага, и для собственного понимания того, что творится внутри процесса. В частности, у нас вот проблема в основном проявлялась при большом количестве пользователей, что неудивительно, так как сессии довольно большие, но все равно странно, так как непонятно, чем же занимается в таком случае сборщик мусора? Ну, о причинах этого потом – в примере.

Используем встроенные средства мониторинга ОС

На втором шаге мы пробуем минимальными усилиями разобраться с тем, что у нас происходит с памятью в процессе и сколько памяти у нас выделяется под сессию. Сделать это очень просто при помощи стандартных счетчиков производительности (performance counters) Windows. Нам пригодятся следующие как минимум счетчики, но вы можете воспользоваться и расширенным списком (помните, что включать их нужно для вашего процесса aspnet_wp/w3wp):

.NET CLR Memory/# Bytes in all heaps .NET CLR Memory/# Total committed Bytes .NET CLR Memory/# Total reserved Bytes .NET CLR Memory/Gen 0 heap size .NET CLR Memory/Gen 1 heap size .NET CLR Memory/Gen 2 heap size .NET CLR Memory/Large Object Heap Size

Выглядеть это будет примерно так:

Собственно, здесь мы хотим посмотреть размеры куч всех трех поколений и LOH, а также общую занятую память и committed/reserved bytes. Reserved bytes показывает, сколько наше приложение зарезервировало себе памяти, committed – сколько оно реально из этого количества уже использует. Отличное описание этих и других полезных счетчиков и их назначение можно найти здесь. Итак, запускаем счетчики и Windows Task Manager (с ним будем отслеживать Mem usage и VM usage для процесса aspnet_wp/w3wp), заполняем себе табличку в Excel – и поехали.

Примечание:

Настоятельно рекомендую перед работой с Task Manager прочитать пост Tess. В частности, там можно прочитать вот такую интересную вещь:

"If you want to see this in action, you can create a winforms application and allocate a bunch of objects and see the working set go up, and then if you minimize the app, the working set drops. This doesn't by any means mean that you have just released all this memory. It just means that you are looking at a counter that is totally irrelevant for determining how much stuff you store in memory :) Yet... this is the counter that people most often look at to determine memory usage...

I know that by now you are probably thinking "yeah right", you haven't even heard of this counter before, why would I say that this is the counter most people look at??? The answer is, because most people use task manager to look at memory usage of a process, and specifically look at the Memory Usage column. Surprise surprise:) what this actually shows you is the working set of the process...

If you want to see private bytes which is a far more interesting counter, you should look at the column in task manager that is labeled Virtual Memory Size (yeah, that's really intuitive:)), or better yet, look in performance monitor at process\private bytes and process\virtual bytes, there is no reason not to if your intent is to investigate high memory usage or a memory leak. "

Так что будьте осторожны ;)

Логинимся в приложение одним пользователем, делаем замеры, логинимся следующим, делаем замеры. По пути можно попробовать просмотреть разную функциональность системы, чтобы увидеть, где именно мы получаем большое увеличение памяти. По размерам куч видим, как постепенно увеличивается количество памяти, и что у нас чистится GC, а что – нет. По Mem usage и VM usage определяем общее количество используемой памяти и пытаемся путем несложных арифметических операций определить, сколько же все-таки у нас занимает один пользователь в сессии. В нашем случае уже на 10 пользователях приходит понимание, что общее количество памяти растет непомерно и освобождаться почему-то не хочет. Ну, это логично – созданные сессии еще активны и сборщик мусора их собрать не может. Ставим опыт: отпускаем приложение на уровне 700 Мб и уходим на полчаса пить чай. Через полчаса заходим на сайт новым пользователем и делаем очередной замер. Нет, почти ничего не изменилось, используемая память продолжает увеличиваться, хотя должна была существенно уменьшится. Размер одной сессии в среднем – 30-40 Мб, что слишком много. Итак, либо у нас по какой-то причине не очищаются сессии, либо утечка памяти в другом месте. Информации по-прежнему мало. Пора браться за более серьезные инструменты анализа.

Знакомимся с тяжелой артиллерией

В роли тяжелой артиллерии может выступать практически любой performance tool, который умеет нормально мониторить память. Тулов много, но толковую информацию предоставляют единицы. Лично я все не смотрел, но вот мой любимый dotTrace, который не раз помогал мне находить performance-проблемы в коде, здесь полностью облажался. Ничего толкового из него я добиться не смог, может, просто руки кривые :) Поэтому, если у вас нет особых вариантов, то советую сразу же взяться за WinDbg. WinDbg – это универсальный дебаггер, которая позволяет отлаживать любые win-приложения. А самое классное в нем то, что он позволяет не только подключаться к приложению и отлаживать в онлайн-режиме, но умеет еще и анализировать т.н. user dump’ы, то есть снимки внутреннего состояния приложения. Сделать эти снимки можно при помощи тулы User Mode Process Dumper, а WinDbg можно найти в пакете Debugging Tools for Windows. Итак, выполним подготовительные действия по шагам:

1) Устанавливаем оба пакета: Dumper на сервер приложения, Tools на девелоперскую.
2) Загружаем наше приложение так, чтобы оно начало валяться и дрыгать ногами. Необязательно добиваться OutOfMemoryException, можно просто подождать, пока приложение скушает около гигабайта памяти.
3) Делаем дамп памяти, запустив userdump.exe из соответствующего каталога как минимум с одним параметром – идентификатором процесса ASP.NET. Узнать pid можно несколькими способами, самый простой – через колонку PID в Task Manager. Строка запуска будет выглядеть где-то так:
userdump.exe 1234
где 1234 – идентификатор процесса.
Также можно дополнительно указать, куда складывать dump-файл. Если вы не укажете куда, не забудьте глянуть, что по этому поводу вам напишет userdump. Дамп занимает около минуты, в зависимости от размера процесса.
4) Открываем WinDbg и через File -> Open Crash Dump загружаем дамп в приложение

После всех указанных действий вы увидите картинку наподобие следующей:

Анализируем дамп процесса

Первым делом нам необходимо подключить к WinDbg библиотеку команд для отлаживания .NET-приложений. Называется эта библиотека sos.dll и для .NET 2.0 она входит в поставку фреймворка, поэтому лежит обычно по следующему пути:

C:\<windows_home>\Microsoft.NET\Framework\v2.0.50727\sos.dll.

Для .NET 1.1 библиотеку можно найти по немного другому адресу:

%DEBUGGING_TOOLS_HOME%\clr10

Теперь подключаем sos.dll к WinDbg при помощи команды:

.load C:\<windows_home>\Microsoft.NET\ Framework\v2.0.50727\sos.dll

Теперь наш дебаггер пополнился кучей дополнительных команд. Чтобы посмотреть их все, наберите в консоли команду "!help". Вот список команд версии sos.dll для .NET 2.0:

Как видите, команд здесь довольно много. Я не буду останавливаться на всех них. Подробное описание процесса инсталляции и команд можно найти в секции Debugging School блога Johan Straarup:

Инсталляция: How to install Windbg and get your first memory dump
Список комманд: Getting started with windbg - part I, Getting started with windbg - part II, Using WinDbg - Advanced commands
Решение различных проблем: Using WinDbg - Hunting Exceptions, Walkthrough - Troubleshooting a native memory leak

Теперь, когда мы знаем минимально необходимый набор команд, я покажу приблизительный алгоритм поиска источника проблемы.

Начнем мы с анализа памяти. Проверим, что у нас вообще творится в куче:

0:000> !eeheap -gc
Number of GC Heaps: 8
------------------------------
Heap 0 (000dacf8)
generation 0 starts at 0x33187580
generation 1 starts at 0x33180038
generation 2 starts at 0x02960038
ephemeral segment allocation context: none
segment begin allocated size
1b63e3f0 6c10260c 6c105d38 0x0000372c(14124)
1b5fd5b0 7b463c40 7b47a744 0x00016b04(92932)
1b5ce420 6c267294 6c26d410 0x0000617c(24956)
000eb0d8 7a733370 7a754b98 0x00021828(137256)
000e8750 790d8620 790f7d8c 0x0001f76c(128876)
02960000 02960038 048419dc 0x01ee19a4(32381348)
33180000 33180038 332cb58c 0x0014b554(1357140)
Large object heap starts at 0x12960038
segment begin allocated size
12960000 12960038 1394a698 0x00fea660(16688736)
29fa0000 29fa0038 2a82b8c0 0x0088b888(8960136)
Heap Size 0x3904120(59785504)
------------------------------
Heap 1 (000dbcd0)
...
Heap Size 0x4195f68(68771688)
------------------------------
Heap 2 (000dd1e8)
...
Heap Size 0x3d09fb4(64004020)
------------------------------
Heap 3 (000de6d0)
...
Heap Size 0x38a3fbc(59391932)
------------------------------
Heap 4 (000dfdf0)
...
Heap Size 0x390c360(59818848)
------------------------------
Heap 5 (000e10f0)
...
Heap Size 0x36b2fc8(57356232)
------------------------------
Heap 6 (000e2600)
...
Heap Size 0x3f69ef8(66494200)
------------------------------
Heap 7 (000e3b10)
...
Heap Size 0x39411f0(60035568)
------------------------------
GC Heap Size 0x1d8b2408(495657992)

Я сознательно опустил некоторые не очень важные подробности. Главное, что мы отсюда видим – что у нас 8 куч (по количеству ядер, виртуальных, и не только) и общий размер этих куч составляет около полугигабайта, что есть немало. Значит, кто-то там живет. Теперь выведем статистику по хранящимся в куче объектам:

0:000> !dumpheap -stat
------------------------------
Heap 0
total 359790 objects
------------------------------
Heap 1
total 325369 objects
------------------------------
Heap 2
total 384784 objects
------------------------------
Heap 3
total 424903 objects
------------------------------
Heap 4
total 379269 objects
------------------------------
Heap 5
total 346442 objects
------------------------------
Heap 6
total 410719 objects
------------------------------
Heap 7
total 367846 objects
------------------------------
total 2999122 objects
Statistics:
MT Count TotalSize Class Name
7ae7ab58 1 12 System.Drawing.ColorConverter
7a776af8 1 12 System.Diagnostics.CorrelationManager
7a75b4dc 1 12 System.CodeDom.Compiler.CodeDomConfigurationHandler
7a75b1ac 1 12 System.Net.DefaultCertPolicy
7a75a2e4 1 12 System.ComponentModel.TimeSpanConverter
7a759dc4 1 12 System.ComponentModel.SingleConverter
7a759c2c 1 12 System.ComponentModel.Int32Converter
7a759b5c 1 12 System.ComponentModel.StringConverter
7a759a70 1 12 System.ComponentModel.DoubleConverter
7a759824 1 12 System.ComponentModel.BooleanConverter
...
6639d878 1 12 System.Web.Caching.Cache
...
663b0cdc 6 288 System.Web.SessionState.InProcSessionState
...
6641194c 39326 629216 System.Web.UI.StateBag
1f49c0c4 11174 670440 System.Data.Objects.DataClasses.EntityReference`1[[Custom.Domain.Model.Identity, CUSTOM.Domain]]
79104368 29236 701664 System.Collections.ArrayList
1f4e6b2c 6899 814452 System.Collections.Generic.Dictionary`2+Entry[[System.String, mscorlib],[System.Data.Mapping.ObjectMemberMapping, System.Data.Entity]][]
7a7580d0 42592 851840 System.Collections.Specialized.HybridDictionary
79109778 16469 922264 System.Reflection.RuntimeMethodInfo
7a75820c 33900 949200 System.Collections.Specialized.ListDictionary
1f47b648 24872 994880 System.Collections.Generic.HashSet`1[[System.Data.Mapping.ViewGeneration.Structures.CellConstant, System.Data.Entity]]
1ed28b24 26572 1169168 Custom.Domain.Model.ModelChangeNotification
663c1de8 76432 1222912 System.Web.UI.StateItem
1f47d600 24872 1273584 System.Collections.Generic.HashSet`1+Slot[[System.Data.Mapping.ViewGeneration.Structures.CellConstant, System.Data.Entity]][]
7912d9bc 6241 1379616 System.Collections.Hashtable+bucket[]
1f670640 59056 1417344 System.Collections.Generic.List`1[[System.Data.Objects.DataClasses.RelatedEnd, System.Data.Entity]]
7a7582d8 75305 1506100 System.Collections.Specialized.ListDictionary+DictionaryNode
1fb88ec4 27196 1631760 System.Data.Objects.DataClasses.EntityReference`1[[Custom.Domain.Model.ChangeSet, CUSTOM.Domain]]
79102290 141087 1693044 System.Int32
1f67044c 60893 1705004 System.Data.Objects.DataClasses.RelationshipManager
1f671b90 69 1826948 System.Collections.Generic.Dictionary`2+Entry[[System.Data.EntityKey, System.Data.Entity],[System.Data.Objects.ObjectStateEntry, System.Data.Entity]][]
1f6720fc 116747 2334940 System.Data.Objects.RelationshipWrapper
1f497584 49230 2953800 System.Data.Objects.DataClasses.EntityReference`1[[Custom.Domain.Model.User, CUSTOM.Domain]]
7912dae8 3769 3262224 System.Byte[]
1f670984 66309 3448068 System.Data.Objects.EntityEntry
1f672fec 64 3699100 System.Collections.Generic.Dictionary`2+Entry[[System.Data.Objects.RelationshipWrapper, System.Data.Entity],[System.Data.Objects.ObjectStateEntry, System.Data.Entity]][]
1f6743a4 164482 3947568 System.Data.Objects.DataClasses.RelationshipNavigation
1f65151c 118239 4729560 System.Data.EntityKey
1f67223c 116740 6070480 System.Data.Objects.RelationshipEntry
7912d7c0 55276 6703116 System.Int32[]
7912d8f8 224375 12356408 System.Object[]
000d9080 1518 31164860Free
790fd8c4 318231 362482876 System.String

Здесь мы тоже видим довольно много интересного. Во-первых, для будущих тестов нам нужны MT (что-то типа идентификатора типа объекта) объектов System.Web.Caching.Cache и System.Web.SessionState.InProcSessionState, которые соответствуют глобальному кешу приложения и его сессиям, которые наравне с другими объектами кеша хранятся в нем. Еще мы видим, что у нас очень много объектов хранится в массивах строк, но толку нам пока от этого немного. Вот если бы там были какие-то более специфические объекты, например, DataTable, мы могли бы туда сходить и посмотреть более серьезно. А так глянем сначала, сколько у нас занимается кеш в целом и сессии в частности. Для этого сначала нужно найти адреса этих объектов:

0:000> !dumpheap -mt 6639d878
------------------------------
Heap 0
Address MT Size
total 0 objects
------------------------------
Heap 1
Address MT Size
total 0 objects
------------------------------
Heap 2
Address MT Size
total 0 objects
------------------------------
Heap 3
Address MT Size
total 0 objects
------------------------------
Heap 4
Address MT Size
total 0 objects
------------------------------
Heap 5
Address MT Size
total 0 objects
------------------------------
Heap 6
Address MT Size
0e961294 6639d878 12
total 1 objects
------------------------------
Heap 7
Address MT Size
total 0 objects
------------------------------
total 1 objects
Statistics:
MT Count TotalSize Class Name
6639d878 1 12 System.Web.Caching.Cache
Total 1 objects
0:000> !objsize 0e961294
sizeof(0e961294) = 336106272( 0x14089320) bytes (System.Web.Caching.Cache)
0:000> !dumpheap -mt 663b0cdc
------------------------------
Heap 0
Address MT Size
0355a598 663b0cdc 48
03969aa0 663b0cdc 48
039711e4 663b0cdc 48
total 3 objects
------------------------------
Heap 1
Address MT Size
total 0 objects
------------------------------
Heap 2
Address MT Size
07f62150 663b0cdc 48
total 1 objects
------------------------------
Heap 3
Address MT Size
08f53ec8 663b0cdc 48
total 1 objects
------------------------------
Heap 4
Address MT Size
total 0 objects
------------------------------
Heap 5
Address MT Size
total 0 objects
------------------------------
Heap 6
Address MT Size
total 0 objects
------------------------------
Heap 7
Address MT Size
10d01948 663b0cdc 48
total 1 objects
------------------------------
total 6 objects
Statistics:
MT Count TotalSize Class Name
663b0cdc 6 288 System.Web.SessionState.InProcSessionState
Total 6 objects

Итак, кеш весит 336 Мб, а сессий у нас 6 штук. Берем первую попавшуюся и смотрим ее размер:

0:000> !objsize 0355a598
sizeof(0355a598) = 335808888( 0x14040978) bytes (System.Web.SessionState.InProcSessionState)

Смотрим следующую – размер тот же, причем до байта. Еще одну – аналогично. Явно что-то не так в датском королевстве. Суммарный размер 6 сессий будет явно превышать размер объекта кеша, чего не может быть в принципе, так как объект Cache содержит в себе сессии. Однако, здесь есть особенность, которая может объяснить эту нестыковку – дело в том, что sos при подсчете размера объекта включает в него и размер всех объектов, на которые данный объект ссылается. Значит, у нас где-то сессии друг на друга ссылаются. Вот только где и как? Кроме того, мы можем сделать еще один важный вывод: чистая информация, которую мы вносили в кеш руками, занимает очень мало памяти, что очень хорошо. Если бы разница была больше, то нужно было бы идти анализировать еще и закешированные данные.

Посмотрим, что у нас хранится в сессии:

0:000> !do 10d01948
Name: System.Web.SessionState.InProcSessionState
MethodTable: 663b0cdc
EEClass: 663b0c6c
Size: 48(0x30) bytes
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name
663ea4e4 4001edc 4 ...ateItemCollection 0 instance 0704f73c _sessionItems
663a9944 4001edd 8 ...ObjectsCollection0 instance 00000000 _staticObjects
79102290 4001ede c System.Int32 1 instance 25 _timeout
7910be50 4001edf 18 System.Boolean 1 instance 0 _locked
7910c878 4001ee0 1c System.DateTime 1 instance 10d01964 _utcLockDate
79102290 4001ee1 10 System.Int32 1 instance 36 _lockCookie
663a7220 4001ee2 24 ...ReadWriteSpinLock 1 instance 10d0196c _spinLock
79102290 4001ee3 14 System.Int32 1 instance 0 _flags
0:000> !do 0704f73c
Name: System.Web.SessionState.SessionStateItemCollection
MethodTable: 664107dc
EEClass: 66410764
Size: 60(0x3c) bytes
(C:\WINDOWS\assembly\GAC_32\System.Web\2.0.0.0__b03f5f7f11d50a3a\System.Web.dll)
Fields:
MT Field Offset Type VT Attr Value Name
7910be50 4001172 24 System.Boolean 1 instance 0 _readOnly
79104368 4001173 4 ...ections.ArrayList 0 instance 0704f784 _entriesArray
79116ef8 4001174 8 ...IEqualityComparer0 instance 02961a28 _keyComparer
79101fe4 4001175 c ...ections.Hashtable 0 instance 0704f79c _entriesTable
7a75a878 4001176 10 ...e+NameObjectEntry 0 instance 00000000 _nullKeyEntry
7a772bc4 4001177 14 ...se+KeysCollection 0 instance 00000000 _keys
79111df0 4001178 18 ...SerializationInfo 0 instance 00000000 _serializationInfo
79102290 4001179 20 System.Int32 1 instance 6 _version
790fd0f0 400117a 1c System.Object 0 instance 00000000 _syncRoot
791168f8 400117b 538 ...em.StringComparer 0 shared static defaultComparer
>> Domain:Value 000c8390:NotInit ... <<
7910be50 4001f2b 25 System.Boolean 1 instance 1 _dirty
66421eb8 4001f2c 28 ...n+KeyedCollection 0 instance 00000000 _serializedItems
79101924 4001f2d 2c System.IO.Stream 0 instance 00000000 _stream
79102290 4001f2e 34 System.Int32 1 instance 0 _iLastOffset
790fd0f0 4001f2f 30 System.Object 0 instance 0704f778 _serializedItemsLock
79101fe4 4001f2a c5c ...ections.Hashtable 0 shared static s_immutableTypes
>> Domain:Value 000c8390:NotInit ... <<
0:000> !do 0704f784
Name: System.Collections.ArrayList
MethodTable: 79104368
EEClass: 791042bc
Size: 24(0x18) bytes
(C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
Fields:
MT Field Offset Type VT Attr Value Name
7912d8f8 40008ea 4 System.Object[] 0 instance 10d0189c _items
79102290 40008eb c System.Int32 1 instance 2 _size
79102290 40008ec 10 System.Int32 1 instance 2 _version
790fd0f0 40008ed 8 System.Object 0 instance 00000000 _syncRoot
7912d8f8 40008ee 1c0 System.Object[] 0shared static emptyArray
>> Domain:Value 000c8390:08961f48 ...<<
0:000> !da 10d0189c
Name: System.Object[]
MethodTable: 7912d8f8
EEClass: 7912de6c
Size: 32(0x20) bytes
Array: Rank 1, Number of elements 4, Type CLASS
Element Methodtable: 790fd0f0
[0] 10d0188c
[1] 034f5ccc
[2] null
[3] null
0:000> !do 10d0188c
Name: System.Collections.Specialized.NameObjectCollectionBase+NameObjectEntry
MethodTable: 7a75a878
EEClass: 7a7c51c4
Size: 16(0x10) bytes
(C:\WINDOWS\assembly\GAC_MSIL\System\2.0.0.0__b77a5c561934e089\System.dll)
Fields:
MT Field Offset Type VT Attr Value Name
790fd8c4 400117c 4 System.String 0 instance 0698fdd8 Key
790fd0f0 400117d 8 System.Object 0 instance 030cc5d8 Value
0:000> !do 030cc5d8
Name: Custom.Namespace.SomeClass
MethodTable: 1b109548
EEClass: 1d351918
Size: 116(0x74) bytes
(C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\Temporary ASP.NET Files\someApp-3.7.23.30\196191ae\903c3217\assembly\dl3\5f395f40\004dd5b1_3ffec801\Custom.UI.Web.DLL)
Fields:
MT Field Offset Type VT Attr Value Name
1b10e18c 400006e 4 ...del.DomainContext 0 instance 030cc6f0 model
1b10d484 400006f 8 ...OrganizationScope0 instance 0ec75578 scopeModel
1fe48b6c 4000070 c ...el.TotalViewModel 0 instance 00000000 totalViewModel
1b3dac14 4000071 10 ...odel.Organization 0 instance 08f552bc organizationModel
1fb80314 4000072 14 ...on.Model.Variable 0 instance 00000000 variableModel
1fbe7afc 4000073 18 ...Model.Requirement 0 instance 00000000 requirementModel
1b3dbcc4 4000074 1c ...n.Model.Objective 0 instance 00000000 objectiveModel
1fbe938c 4000075 20 ...uirementAttribute 0 instance 0f3843ac requirementAttributeModel
7910ff9c 4000076 24 System.Void 0 instance 00000000 requirementAttributeClassModel
1b3dba6c 4000077 28 ...ion.Model.Project 0 instance 00000000 projectModel
1b3db714 4000078 2c ...cation.Model.Task 0 instance 00000000 taskModel
7910ff9c 4000079 30 System.Void 0 instance 00000000 profileModel
1b3db48c 400007a 34 ...on.Model.Resource 0 instance 00000000 resourceModel
7910ff9c 400007b 38 System.Void 0 instance 00000000 commentModel
1ed25b14 400007c 3c ...on.Model.Identity 0 instance 00000000 identityModel
30f67d1c 400007d 40 ....Model.DataModule 0 instance 00000000 dataModuleModel
1ed25e14 400007e 44 ...cation.Model.User 0 instance 0ec74f7c userModel
1fb81614 400007f 48 ...cation.Model.Role 0 instance 0ec75068 roleModel
1fb8146c 4000080 4c ...Web.Model.CCFUser 0 instance 0ec74ffc currentUser
1b3db174 4000081 50 ...tion.Model.Folder 0 instance 0f36b6d4 folderModel
1fc814c4 4000082 54 ...on.Model.Document 0 instance 0d0d93cc documentModel
1b10ed0c 4000083 58 ...on.Model.Workflow 0 instance 030cc66c workflowModel
1fc83ebc 4000084 5c ...odel.Notification 0 instance 031958ec notificationModel
7910ff9c 4000085 60 System.Void 0 instance 00000000 reportModel
1b10f6fc 4000086 64 ...n.Model.ChangeSet 0 instance 050cc0a0 changeSetModel
7910ff9c 4000087 68 System.Void 0 instance 00000000 scheduledTasksManagerModel
1b3dc034 4000088 6c ...esWorkflowMonitor 0 instance 00000000 changesWorkflowMonitor
1fb8c638 4000089 34 ...hing.RequestCache 0 static 109e1158 requestCache
1fe44870 400008a 38 ....ApplicationCache 0 static 0aee10c4 applicationCache
1ed24714 400008b 3c ...g.StatisticsCache 0 static 0c9a4e7c statisticsCache

Как мы видим, в сессии хранится лишь некий экземпляр класса Custom.Namespace.SomeClass, который содержит перечисленный набор полей. В принципе, это известно давно тем, кто приложение программировал :) Колонка Value показывает значения ссылок, нолики, как несложно догадаться – это null. Теперь посмотрим размеры объекта model:

0:000> !objsize 030cc6f0
sizeof(030cc6f0) = 335808160( 0x140406a0) bytes (Custom.Namespace.SomeAnotherClass)
0:000> !do 030cc6f0
Name: Custom.Namespace.SomeAnotherClass
MethodTable: 1b10e18c
EEClass: 1d35c7d8
Size: 48(0x30) bytes
(C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\Temporary ASP.NET Files\someApp-3.7.23.30\196191ae\903c3217\assembly\dl3\0a41ba0b\0020a4b0_3ffec801\Custom.Application.DLL)
Fields:
MT Field Offset Type VT Attr Value Name
1dad2c38 4000119 4 ...Views.DomainLogic 0 instance 050cbf34 context
7910be50 400011a 28 System.Boolean 1 instance 0 isChanged
00000000 400011b 8 0 instance 030cc720 workflowModelChanges
00000000 400011c c 0 instance 030cc738 notificationsChanges
1fb804fc 400011d 10 ...olledBackDelegate 0 instance 0f3843e4 ContextRolledBack
1fb805ec 400011e 14 ...RefreshedDelegate 0 instance 0f384424 ContextRefreshed
1b10f4d4 400011f 18 ...extSavingDelegate 0 instance 050cc040 ContextSaving
1b10f8e4 4000120 1c ...textSavedDelegate 0 instance 0d0d9cbc ContextSaved
1fb806dc 4000121 20 ...aveFailedDelegate 0 instance 0f384464 ContextSaveFailed
1b10f5c4 4000122 24 ...CancelledDelegate 0 instance 050cc060 ContextSaveCancelled
7910be50 4000123 29 System.Boolean 1 instance 0k__BackingField
0:000> !objsize 050cbf34
sizeof(050cbf34) = 63643700 ( 0x3cb2034) bytes (Custom.Namespace.OneMoreAnotherClass)

Итак, главный объект SomeAnotherClass весит около 335 Мб, в то время как вложенный в него OneMoreAnotherClass – всего 63 Мб. Возможно, другие объекты содержат остальные данные? Проверяем – нет, не так. Хотя в нашем случае даже проверять не нужно было – мы и так знаем свой код :) Проверяем другие сессии аналогичным образом – там та же картина, что вполне ожидаемо. Итак, к чему мы пришли? Наш Custom.Namespace.SomeClass и вложенный в него Custom.Namespace.SomeAnotherClass содержится в каждой сессии, а то, что objsize показывает для него размер всех сессий, указывает, что на этом уровне у нас возможны проблемы.

А теперь посмотрим, кто на кого ссылается:

0:000> !gcroot 030cc6f0
Note: Roots found on stacks may be false positives. Run "!help gcroot" for more info.
Scan Thread 17 OSTHread c64
Scan Thread 27 OSTHread 1c24
Scan Thread 28 OSTHread 824
Scan Thread 29 OSTHread 1d68
Scan Thread 15 OSTHread 1ee4
Scan Thread 31 OSTHread ec4
Scan Thread 32 OSTHread 1ea4
Scan Thread 33 OSTHread 1e9c
Scan Thread 34 OSTHread 3ec
Scan Thread 35 OSTHread 1e10
Scan Thread 36 OSTHread 6ec
Scan Thread 37 OSTHread c90
Scan Thread 38 OSTHread b6c
ESP:1f17ecbc:Root:069b83b8(Microsoft.Practices.EnterpriseLibrary.Common.Configuration.Storage.ConfigurationChangeFileWatcher)->
069b8514(System.Threading.Thread)->
08963fe0(System.Runtime.Remoting.Contexts.Context)->
08963e40(System.AppDomain)->
0a935d24(System.ResolveEventHandler)->
0a0e9918(System.Object[])->
0e9a9c34(System.ResolveEventHandler)->
0e9a9250(System.Web.Compilation.BuildManager)->
0e9a9e38(System.Web.Compilation.MemoryBuildResultCache)->
0e96137c(System.Web.Caching.CacheMultiple)->
0e961394(System.Object[])->
0e9679dc(System.Web.Caching.CacheSingle)->
0e967aa0(System.Web.Caching.CacheExpires)->
0e967ac0(System.Object[])->
0e9685d4(System.Web.Caching.ExpiresBucket)->
118ede14(System.Web.Caching.ExpiresPage[])->
118ede98(System.Web.Caching.ExpiresEntry[])->
03971214(System.Web.Caching.CacheEntry)->
039711e4(System.Web.SessionState.InProcSessionState)->
0b5fa220(System.Web.SessionState.SessionStateItemCollection)->
0b5fa280(System.Collections.Hashtable)->
0b5fa2b8(System.Collections.Hashtable+bucket[])->
03971170(System.Collections.Specialized.NameObjectCollectionBase+NameObjectEntry)->
0d7b54d4(Custom.Namespace.SomeClass)->
0d7b5568(Custom.Application.Model.Workflow)->
0d7b55ac(Custom.Application.Model.Workflow+WorkflowRemindDelegate)->
0698fec8(Custom.ApproveActionWorkflow.WorkflowManager)->
11bdadd4(Custom.ApproveActionWorkflow.WorkflowManager+WorkflowNotificationsSentDelegate)->
03971088(System.Object[])->
050cc020(Custom.ApproveActionWorkflow.WorkflowManager+WorkflowNotificationsSentDelegate)->
030cc6f0(Custom.Namespace.SomeAnotherClass)
DOMAIN(001020B0):HANDLE(Strong):29310e0:Root:0e968b38(System.Threading._TimerCallback)->
0e968af0(System.Threading.TimerCallback)->
0e964010(System.Web.Caching.CacheExpires)->
0e964030(System.Object[])->
0e9646f8(System.Web.Caching.ExpiresBucket)->
0517489c(System.Web.Caching.ExpiresPage[])->
05174920(System.Web.Caching.ExpiresEntry[])->
10d01978(System.Web.Caching.CacheEntry)->
10d01948(System.Web.SessionState.InProcSessionState)->
0704f73c(System.Web.SessionState.SessionStateItemCollection)->
0704f79c(System.Collections.Hashtable)->
0704f7d4(System.Collections.Hashtable+bucket[])->
10d0188c(System.Collections.Specialized.NameObjectCollectionBase+NameObjectEntry)->
030cc5d8(Custom.Namespace.SomeClass)->
030cc6f0(Custom.Namespace.SomeAnotherClass)

А вот и корень зла. Если посмотреть этот trace, то можно увидеть, что поначалу у нас все замечательно, кеш, сессия, а потом начинаются странности. Откуда-то появляются ссылки через делегаты, а класс SomeAnotherClass вообще фигурирует дважды, причем по разным адресам. Однако подсказка тоже есть – Custom.ApproveActionWorkflow.WorkflowManager+WorkflowNotificationsSentDelegate. Немного подумав, вспоминаем, что у нас есть замечательный синглтон-класс WorkflowManager, который предназначен для взаимодействия между пользовательскими потоками и потоком WorkflowRuntime, и оповещает все сессии при помощи генерации события о том, что им пора бы обновить некоторые специфические данные из базы. И он, конечно же, подписывает все создаваемые сессии на свое событие. А потом держит эту ссылку бесконечно, таким образом не давая сборщику мусора собрать сессии. Ну все, разобрались. Теперь дело за малым: зарефакторить код, чтобы сессии сами опрашивали класс об изменениях и избавиться от OutOfMemoryException :) Дело сделано.

Выводы

Выводы из данной ситуации очень простые:

1) Делегаты, как оказывается – звери совсем не безобидные, за ними тоже нужен глаз да глаз
2) Старайтесь внимательно реализовывать межсессионное взаимодействие, чтобы не допускать не только ссылок на объекты, но и на функции
3) Не забывайте про особенности работы Task Manager и то, что он реально показывает. Не нужно на него сильно полагаться
4) Если же у вас все-таки вылетает OutOfMemoryException, не отчаивайтесь. Вооружайтесь дампом и WinDbg – и вперед. Люди и не такие баги отлаживают :)
5) WinDbg подойдет и для отладки других сложных ситуаций. Вот, например, рассказ Юры Скалецкого и некоего JKealey. Там есть что почитать.

Ну, и напоследок я настоятельно вам советую следующие статьи из блога Tess и Johan’а по поводу отладки утечек памяти:

Debugging Script: Dumping out ASP.NET Session Contents
ASP.NET Memory Leak Case Study: Sessions Sessions Sessions…
ASP.NET Memory - How much are you caching? + an example of .foreach
ASP.NET Case Study: Tracing your way to Out Of Memory Exceptions
Why adding more memory won't resolve OutOfMemoryExceptions
I am getting OutOfMemoryExceptions. How can I troubleshoot this?
Are you getting OutOfMemoryExceptions when uploading large files?

Да и вообще, эти блоге стоит добавить в ваш персональный RSS feeder. Можно вместе с блогом Марка Руссиновича (ага, это тот, который написал кучу полезных системных тулов, известных под названием Sysinternals). Пригодятся.

Успехов в отладке!