Нечасто встречаются истории, когда причины и следствия сплетаются в один клубок, связывающий проблемы и с памятью, и с CPU, и с тредпулом. А инструментально затрагивающие и пулы объектов, и Lazy, и работу с асинхронностью, и длительные вычисления. А ещё реже встречаются те, где всё это распутывается и исправляется буквально несколькими строчками кода.

Введение

Наверное, в любой крупной компании есть древние сервисы-мамонты, которые давным давно работают и не требуют к себе внимания. Иногда, заглянув в них поглубже, можно обнаружить очень занимательные вещи. Так, на примере одного такого из реальной жизни, удалось классно продемонстрировать, как может выстрелить комбинация из неограниченного пула объектов, Lazy, асинхронного кода и длительных CPU-bound задач!

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

Сервис называется ClusterConfig. Если не вдаваться в его бизнес-специфику, он занимается тем, что хранит тысячи деревьев объектов (каждое размером ~15MB), регулярно и оперативно раздаёт их сериализованными и сжатыми тысячам бекендов – но только если дерево поменялось с момента последней метки, которую хранит бекенд после предыдущей попытки скачать его.

И нужно добавить несколько свойств, чтобы сложилась полная картинка. 

Деревья эти меняются редко (примерно все враз, примерно раз в несколько минут), а спрашивают их очень часто: суммарно 3к RPS. Но так как сериализация и сжатие – довольно дорогая процедура, то каждая реплика ClusterConfig сериализует и сжимает эти деревья один раз и раздаёт уже готовые буферы с ответом. Заново сериализует и сжимает деревья только если они поменялись. И благодаря тому, что из тысяч деревьев в каждом диапазоне времени в несколько минут нужны только несколько сотен (но никогда заранее не известно, какие именно понадобятся), эта сериализация и сжатие спрятаны за Lazy.

Зачинщик истории

Триггером к сегодняшней истории было высокое потребление памяти сервиса ClusterConfig. За те долгие года, когда на него не обращали внимание, он раздулся достаточно, чтобы за него зацепился взгляд. С желания чуть-чуть уменьшить его размер всё и началось.

Анализ ситуации

Начинается всё, как и положено, с изучения ситуации. 

Метрики

Вот системные метрики процессов ClusterConfig:

Что мы видим: 

1. 8-9GB RAM на процесс. Не так уж и много, но и весьма не мало.

2. ~5-10% времени работы процесса уходит на работу GC.

3. Резкие и высокие пики потребления тредпула, иногда чуть выше сконфигурированного MinThreads = 256. Коррелируют с моментами перестроения всех деревьев.

4. Резкие пики CPU под 100% (единица на графике – это 100%). Совпадают один в один с моментами перестроения всех деревьев, а также совпадают с некоторыми пиками тредупула.

Изучаем dump

Воспользуемся dotmemory.

Видим очень большой LOH, целых 5.89GB, да ещё и с неприятной фрагментацией: 1.45GB из них — это дырки. В gen2, кстати, тоже не очень приятная фрагментация — 780MB пустот.

Заглянем в детали, на что больше всего ушло памяти среди живых объектов. В этом нам поможет вкладка Dominators:

Я сразу раскрыл самые интересные ветки в дереве справа. Давайте обратим на них внимание, сверху вниз:

1. 2.63 GB потрачено на байтовые массивы в UnboundedObjectPool<BinaryBufferWriter> и в UnboundedObjectPool<MemoryStream>. Звучит очень привлекательно для нас!

2. 2.07 GB потрачено на хранение полезной информации: ZonesLookup и всё, что под ним. Это важное и полезное: там хранятся наши деревья и сериализованные ответы. Не меняя бизнес-логики работы сервиса и контрактов, поделать с этим мы вряд ли что-то сможем.

Получается, вот что в процессе из 8GB подозрительно: 1.5GB потрачено на фрагментацию в LOH, ещё 700MB на фрагментацию в Gen2; ещё 2.6GB потрачено на какие-то пулы.

Ищем способы оптимизаций

Для начала стоит напомнить картинку:

Примерно 50% от всего объема живых объектов занимают UnboundedObjectPool<BinaryBufferWriter> и UnboundedObjectPool<MemoryStream> (Жёлтенькое и зелёненькое сверху диаграммы). По коду и дампу было тривиально вычислить, откуда эти штуки. Это пулы с буферами для сериализации деревьев и их сжатия.

Важно указать, как ими пользуются. Псевдокод, условно, такой:

using (BinaryWriterPool.Acquire(out var writer))
{
   serializer.Serialize(tree, writer);

   using (MemoryStreamPool.Acquire(out var stream))
   {
       using (var gzip = new GZipStream(stream, CompressionMode.Compress, true))
       {
           gzip.Write(writer.Buffer, 0, writer.Length);
           gzip.Flush();
       }

       return new SerializedTree(stream.ToArray());
   }
}

Смотрите внимательно, что происходит: 

1. Берётся Writer из пула, в него сериализуется дерево (под Writer массив byte[], который динамически ресайзится до нужного размера, если не влезло). 

2. Берётся MemoryStream из пула (под MemoryStream тоже просто массив byte[], который динамически ресайзится до нужного размера, если не влезло), в него сжимается результат.

3. У результата делают ToArray(), создавая ещё один новый byte[], и уже его сохраняют и используют дальше.

4. MemoryStream с раздутым byte[] внутри возвращается в пул.

5. Writer с раздутым byte[] внутри возвращается в пул.

Отдельно важно, что эти пулы неограниченного размера: они же UnboundedObjectPool. Если в 100 деревьев одновременно прилетит запрос, а сериализованных ответов для них нет, в пуле BinaryWriterPool окажется 100 буферов с размером сериализованного результата навечно, потому что они одновременно будут сериализовываться и одновременно возьмут буфер из пула, то есть создадут его, раздуют и наполнят байтами, и вернут обратно в пул. И то же самое с MemoryStreamPool.

И это подтверждается дампом. Посмотрите внимательнее на картинку, там 134 byte[] в BinaryWriterPool и 131 byte[] в MemoryStreamPool:

То есть у нас в процессе висят 265 массивов byte[], суммарно на 2.63GB, которые нужны на несколько десятков секунд раз в несколько минут, когда нужно пересчитать все ответы. Всё остальное время они живут просто так, занимают много места и заставляют паниковать GarbageCollector.

Что можно поделать

Очевидно, хочется что-то поделать с тем, чтобы не тратить попусту столько памяти.

Первая наивная мысль была такая — выбросить совсем эти пулы. Мы ведь всё равно в конце делаем ToArray(), всё равно аллоцируем byte[], в котором будем хранить результат до следующего перестроения. Может быть, зааллоцируем чуть больше — промежуточный буфер для сериализации — и выбросим его в конце, заплатив чуть большим GC? Да, такая попытка была. И она не сработала — промежуточные буферы, которые создавались сразу в LOH (а иногда и ресайзились так же в LOH) и потом выбрасывались, под большой конкуренцией, делали LOH ОЧЕНЬ фрагментированым. В итоге, потребление памяти стало ещё больше (хотя объектов стало меньше) вплоть до OOM-ов. Выбросили эту идею.

Вторая мысль была уже более глубокая. 

Зачем нужны пулы? Чтобы оптимизировать какие-то тяжелые действия. В частности, создания тяжелых объектов, которые потом пришлось бы выбрасывать GarbageCollector-у. Что мы делаем с ними в нашем коде? Сериализуем в них огромные деревья. Какая это работа? Синхронная, CPU-bound и длительная.

То есть, как бы мы не старались, у нас всё равно ограниченное число ядер. И нет никакого смысла сериализовывать одновременно больше деревьев, чем количество ядер, выделенных нашему процессу. Всё равно все вместе мы их построим за одинаковое время, без разницы, начав строить одновременно все, или управляя параллелизмом так, чтобы одновременно строилось не более, чем CoresCount. 

При этом, ограничивая параллелизм их построения, мы будем уверены: нам одновременно нужно не более, чем CoresCount буферов из пула! И это число явно меньше, чем 134 (в нашем случае процессу выделено 8 ядер).

То есть, нам нужно соорудить асинхронную очередь ограниченного объема для построения деревьев!

Бонус

Повторим предыдущее предложение: «нам нужно соорудить асинхронную очередь ограниченного объема для построения деревьев».

Да, слово асинхронную явно выделено, и это важно. Вспомним графики, где видно пики потребления тредпула: 

В их возникновении тоже виновато наше неправильное управление сериализациями всех деревьев! В сочетании со старым кодом, где использовался Lazy. 

Если одновременно много запросов прилетает за одним и тем же деревом, которое ещё ни разу не было сериализовано, то чтобы не сериализовывать его много раз использовался Lazy<T> с опцией LazyThreadSafetyMode.ExecutionAndPublication. Вполне логичное решение. Lazy решал и ещё одну проблему: у нас тысячи деревьев, и про почти все из них мы заранее не знаем, придут ли вообще за ними. Поэтому и с этой точки зрения было удобно хранить результат сериализации каждого дерева в Lazy<SerializedTree>:

Lazy<SerializedTree> serializedTree = new Lazy<SerializedTree>(
    () => tree.Serialize(), 
    LazyThreadSafetyMode.ExecutionAndPublication);

Теперь давайте представим, что 100 запросов прилетают одновременно за одним деревом и упираются в serializedTree.Value. А он вычисляется, скажем, секунду. Что произойдёт? Все 100 запросов, исполняющихся на тредпуле, на секунду синхронно заблокируются. 

Если то же самое происходит одновременно с сотней деревьев, то вот, у нас уже десять тысяч потоков (если конечно их успеют создать) на тредпуле заблокированы и ждут. Причем ждут они, пока наши бедные 8 ядрышек одновременно пытаются сериализовать 100 деревьев в 100 потоков. То есть это, почти что, смерть процесса.

Реализация оптимизации

Она была предельна проста. Настолько, что захотелось ей поделиться прямо as is. Сделано было всего три действия:

(1) Реализован один новый малюсенький класс SerializationQueue (можно было и без него, сооружая некрасивые try finally на голом семафоре во всех местах использования)

internal class SerializationQueue
{
    private readonly SemaphoreSlim semaphore;
 
    public SerializationQueue(int capacity)
    {
        semaphore = new SemaphoreSlim(capacity);
    }
 
    public async Task<Releaser> GetSlotAsync()
    {
        await semaphore.WaitAsync();
        return new Releaser(semaphore);
    }
 
    internal class Releaser : IDisposable
    {
        private readonly SemaphoreSlim semaphoreSlim;
 
        public Releaser(SemaphoreSlim semaphoreSlim)
        {
            this.semaphoreSlim = semaphoreSlim;
        }
 
        public void Dispose()
        {
            semaphoreSlim.Release();
        }
    }
}

(2) Тривиально переделан Lazy<SerializedTree>

Было

Lazy<SerializedTree> serializedTree = new Lazy<SerializedTree>(
  () => tree.Serialize(), 
  LazyThreadSafetyMode.ExecutionAndPublication);

Стало

Lazy<Task<SerializedTree>> serializedTree = new Lazy<Task<SerializedTree>>(async () =>
    {
        using (await serializationQueue.GetSlotAsync())
        {
            return tree.Serialize();
        }
    },
    LazyThreadSafetyMode.ExecutionAndPublication);

(3) Сделана вся лапша, чтобы дотянуть await до мест использования нового Lazy<Task<SerializedTree>> serializedTree.

Как это работает

Давайте опишем, как сейчас работает запрос «дай новое дерево».

1. Запросы доходитят до Lazy<Task<SerializedTree>> serializedTree, и только один из всех пришедших за определённым деревом создаёт Task. Важно, что он не сериализует дерево, а создаёт таск, который запускает работу, чтобы где-то там на тредпуле это дерево сериализовал какой-то поток. Все эти запросы очень быстро получают какой-то Task из Lazy.

2. Все запросы делают await на этом Task<SerializedTree>. Они не занимают тредпул, а асинхронно ждут результат его выполнения. А если таска уже выполнена и сериализованный ответ уже посчитан, они его мгновенно и синхронно забирают, ничего не ожидая.

3. Где-то в тредпуле крутится много тасок, которые хотят сериализовать дерево. Но сначала они безобидно и асинхронно ждут в очереди SerializationQueue. Дождавшись своего слота, они занимают единицу параллелизма и спокойно сериализуют своё дерево без конкуренции за процессор. После чего возвращают единицу параллелизма обратно в SerializationQueue.

Итого микроскопические и максимально тривиальные изменения в коде, не трогающие почти ничего кроме одной функции внутри Lazy, решают сразу две проблемы: бесполезного замусоривания пулов и скачков потребления тредпула и CPU. Осталось только проверить, сработало ли!

Проверяем результат

Релизим, смотрим на метрики, снимаем дамп.

Если изучить системные метрики, то видно, что среднее потребление CPU немного упало, почти до нуля упал GC time percent. То есть мы что-то улучшили про память, GC стал очень спокойным и почти ничего не делает (а раньше ~10% времени работы процессора уходило именно на GC), соответственно, и потребление CPU упало.

Потребление памяти упало примерно на 2GB, что весьма неплохо и соответствует ожиданиям от уменьшения количества объектов в пулах. И что отдельно очень приятно, полностью пропали пики потребления тредпула.

Теперь посмотрим на новый дамп. Будем сравнивать попарно Новое и Старое.

Видно, что размер LOH существенно сократился. Пропали как раз те самые лишние 2.6GB из LOH и немного уменьшился фрагментированный объем (пустоты). Правда, почему-то стало чуть больше мусора и фрагментации в gen0 и gen1, но нас это пока не интересует (скорее всего, свободной памяти стало больше и GC теперь позволяет себе чуть менее агрессивно заниматься регулярной чисткой и дефрагментацией младших поколений).

Посмотрим детальнее на распределение объектов:

1. Размер всех живых объектов действительно сократился с 5.49GB до 2.83GB. Почти в два раза!

2. ZonesLookup никак не изменился, собственно мы ничего с ним и не делали. Как был 2GB, так и есть. Только теперь этот «полезный объем» не тонет где-то под кучей вспомогательных объектов, а самый первый по размеру, что вроде как и правильно.

3. Массивы byte[] из пулов теперь весят не 2.63GB, а всего 238MB. И там не неограниченно много массивов, а строго столько, сколько у нас ядер. Успех!

Выводы

1. Пулы неограниченного размера — зло. Если возникло желание использовать пул не ограниченного размера — скорее всего это значит, что что-то идёт не так и надо как-то иначе организовать работу, добавить больше контроля над ситуацией.

2. Длительная CPU-bound работа без ограниченного параллелизма — зло. Особенно, если результата её исполнения ожидает кто-то на тредпуле. Вероятно, вам нужен контроль за этой работой, с заданными вами ограничениями.