ОС против Kafka: битва за map-области: история одного неочевидного лимита

Добрый день! Меня зовут Богдан, я тимлид в одном из отечественных финтехов. Сегодня я хочу поделиться нашей историей: как нам удалось, ненарочно, зашедулить падение всех нод одного из наших кластеров Kafka.

В один из холодных февральских дней пришло сообщение от мониторинга с виртуальных машин кластера Kafka: «Свободное дисковое пространство достигло значения < 15%». Было решено исследовать, нужно ли добавлять дискового пространства или же можно потюнить настройки ретеншена данных.

Тут стоит немного вспомнить теорию. Как известно, в Kafka сообщения распределяются по партициям, а каждая партиция на брокере представлена набором сегментов. Число сегментов у партиций может быть разным — оно варьируется в зависимости от интенсивности записи и настроек размера сегмента.

Сегмент (если упростить) — это лог-файл, в который просто пишутся данные в конец. По достижении временного предела либо его размера он ротируется: создается новый сегмент, и запись идет уже в него.

Держа вышесказанное в голове, мы отправились смотреть настройки хранения сегментов в нашем кластере Kafka.

log.retention.hours=336       # время жизни сегмента (в часах), по истечении которого сегмент будет удалён
log.segment.bytes=1073741824  # максимальный размер сегмента (в байтах), при достижении которого создаётся новый сегмент
log.roll.hours=168            # максимальное время (в часах), по истечении которого создаётся новый сегмент, даже если не достигнут лимит размера

Как видно из конфига выше, положение дел у нас было следующее:

• сегменты пересоздаются каждые 7 дней (log.roll.hours),

• либо по достижении ими размера ~1 ГБ (log.segment.bytes).

Удаление сегмента происходит, когда все сообщения в нём становятся старше 336 часов (или 14 дней, log.retention.hours).

Почесав репу на тему «А сколько нам вообще нужно хранить сообщения для нашей прикладной области?», стало понятно, что хранение сообщений старше двух недель не несёт вообще никакого прикладного смысла.

Было решено уменьшить log.roll.hours до суток, чтобы самые старые сообщения дропались быстрее и не ждали, пока все сообщения в «жирном» недельном сегменте состарятся до log.retention.hours.

Настроили следующим образом:

log.retention.hours=336
log.segment.bytes=1073741824
log.roll.hours=24

То есть, теперь мы роллим сегмент каждые 24 часа и удаляем его когда все сообщения в нём становятся старше 7 дней.

Произведя настройки и ребутнув кластер, спустя время мы заметили достаточное увеличение свободного места на дисках и решили, что на этом всё - хэппи-энд. Ресурсы для компании сохранили, сервис работает, метрики в штатных показателях. Но спустя небольшое количество дней среди ночи раздаётся звонок от мониторинга: «Алло, Богдан? Дежурный смены мониторинга. Фиксируем недоступность всех серверов Kafka в кластере N...»

Вообще, честно говоря, за 7 лет работы с Kafka полный отказ всего кластера случался со мной дважды: в этот день и ещё пару лет назад, когда у нас был отказ одного из ЦОД, в котором на тот момент оказался весь кластер Kafka :(

Сейчас же ситуация другая: ЦОД доступен, другие системы работают, а Kafka всеми нодами лежит. Ну да ладно, лирика, — подумал я и полез в логи кафанов. Что же там может быть? А там вот это:

Caused by: java.io.IOException: Map failed
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:940)
    at kafka.log.AbstractIndex.<init>(AbstractIndex.scala:63)
    at kafka.log.OffsetIndex.<init>(OffsetIndex.scala:52)
    at kafka.log.LogSegment.<init>(LogSegment.scala:77)
    at kafka.log.Log.roll(Log.scala:1238)
    at kafka.log.Log.maybeRoll(Log.scala:1194)
    at kafka.log.Log.append(Log.scala:652)
    ... 22 more
Caused by: java.lang.OutOfMemoryError: Map failed
    at sun.nio.ch.FileChannelImpl.map0(Native Method)
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:937)
    ... 28 more

На всехнодах — одна и та же ошибка с последующим падением Kafka. Параллельно пробую запустить кластер (ведь прод стоит, нужно хоть как‑то восстановить сервис, а уже потом разбираться глубже). И — о чудо! — кластер поднимается и работает как ни в чем не бывало.

Возвращаюсь к стектрейсу. Количество вопросов в голове зашкаливает:

• OOM?

• Память утекла?

• В Kafka?

• И почему сразу все ноды упали?

• Как так может быть?

• Что это за зверь?

Начинаю гуглить баг и натыкаюсь на упоминания этой ошибки в одном из блогов:

Kafka uses a LOT of Memory Maps. Running out of them leads to a fatal runtime exception that will kill the broker. If the OS defaults are used, it is extremely likely that those will be reached as soon as the cluster has a few tens of thousand segments per broker. What's worse is that in a well balanced cluster where brokers hold similar numbers of partitions, those failures will occur roughly at the same time.

Each log segment requires an index file and a timeindex file; each of those require 1 map area. Each partition contains a number of log segments. How often Kafka closes a segment and opens a new one depends on segment.bytes and segment.ms.

Не буду подробно останавливаться на Memory Maps в рамках этой статьи - на просторах интернета и Хабра есть годные материалы по этой теме. Скажу лишь, что Kafka активно использует этот механизм для обеспечения высокой скорости чтения/записи, работая с диском как с оперативной памятью. Это позволяет:

• Минимизировать накладные расходы благодаря zero-copy

• Эффективно использовать кэширование ОС

• Ускорять доступ к логам и индексам

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

Возвращаемся к нашим стектрейсам... Прочитав упомянутый блог, невольно вспоминаю недавние изменения в настройках ротации сегментов. Проверяю текущее значение ОСевого параметра vm.max_map_count на нодах кластера и... конечно же, там дефолтное значение:

[root@*** **]# sysctl vm.max_map_count
vm.max_map_count = 65530

Производим тривиальные расчёты: у нас 247 прикладных топиков, 20 партиций на каждый, по новым настройкам каждая партиция может иметь до 7 сегментов, на каждый сегмент требуется 2 memory-mapped области (для index и timeindex файлов).

Итого максимальное возможное количество открытых memory-mapped областей:
247 × 20 × 7 × 2 = 69160 Епть! =D

Тут всё и сложилось окончательно: в кластере 3 ноды, replication factor = 3, на всех нодах количество memory-mapped областей растёт примерно одинаково и как следствие превышение лимита происходит практически одновременно на всех узлах. Соответственно все ноды кластера просто одновременно достигли предельного значения использованных memory-mapped областей и упали, бинго!

По итогам этого инцидента мы:

1. Увеличили vm.max_map_count до 1 000 000 на всех Kafka-нодах.

2. Настроили мониторинг текущих значений memory-mapped.

3. Добавили в скрипты авто развертывания Kafka установку этого параметра в 1кк.

Мораль истории: готовьте кластера правильно, не пренебрегайте настройкой системных параметров в соответствии с best practices и берегите родных и близких. Технические детали: ОС: RHEL 8.6, Kafka: 2.6.0.

P.S. Почему кластер смог подняться после падения (до увеличения vm.max_map_count)?
Моё предположение: часть сегментов удалилась при старте, временно освободив ресурсы. Предлагаю обсудить в комментариях!

P.P.S. Мой канал в телеге — иногда я туда пишу что-то занимательное, с чем сталкиваюсь я и коллеги по ходу работы в наших суровых энтерпрайзах. Тут же в чате можно задать вопрос мне, если таковой имеется, с радостью отвечу!