Практические истории из наших SRE-будней. Часть 2
Утекло уже немало воды с момента публикации нашего последнего очерка об интересных случаях из практики обслуживания Kubernetes-кластеров и запускаемых в нём сервисов/приложений. Хотим представить очередную серию приключений инженеров «Фланта» в неспокойных водах большой (и не очень) веб-разработки.
История №1. Kafka и переменные от Docker«a в K8s
Работа в системах, построенных на контейнерах, постепенно становится стандартом отрасли и многие инструменты уже довольно плотно закрепились в этой среде. Однако по-прежнему можно найти забавные (а иногда и не очень) баги, связанные с интеграцией в инфраструктуру Docker/Kubernetes.
Однажды нам потребовалось развернуть стандартную связку ZooKeeper + Kafka для Sentry, ну и, возможно, других компонентов в будущем. Выглядит не сложно: берем за основу тяжелочитаемый Helm-чарт Kafka из всем известного проекта на GitHub, обрезаем всё лишнее, добавляем своё под нужды проекта.
Пробуем запускать — получаем первую ошибку:
===> Configuring ...
port is deprecated. Please use KAFKA_ADVERTISED_LISTENERS instead.
Странное сообщение — ок, добавим:
env:
- name: KAFKA_ADVERTISED_LISTENERS
value: {{ printf "%s:%s" .Chart.Name .Values.port._default }}
Ситуация повторяется. Возможно, имеет смысл посмотреть, кто и почему это пишет? И тогда встает главный вопрос: какой образ мы используем и что там есть? Чарт из крупнейшего репозитория основан на использовании довольно популярного образа confluentinc/cp-kafka, который имеет широкофункциональный entrypoint (как и у многих других образов Confluent Community). Если же изучить, что и в какой последовательности запускается, можно найти скрипт, в котором и таится источник проблем:
if [[ -n "${KAFKA_PORT-}" ]]
then
echo "port is deprecated. Please use KAFKA_ADVERTISED_LISTENERS instead."
exit 1
fi
Вроде бы всё ясно, но ведь мы эту переменную (да и вообще ничего похожего) не объявляли!…
Однако, если взглянуть на реально объявленные переменные окружения внутри контейнера, обнаружится, что такая переменная действительно существует… как и некоторые другие, подобного ей формата:
root@kafka-0:/# env |grep KAFKA_PORT
KAFKA_PORT_9092_TCP_PORT=9092
KAFKA_PORT_9092_TCP_PROTO=tcp
KAFKA_PORT=tcp://192.168.252.192:9092
KAFKA_PORT_9092_TCP=tcp://192.168.252.192:9092
KAFKA_PORT_9092_TCP_ADDR=192.168.252.192
Всё дело в том, что kubelet при старте pod«а добавляет набор переменных, формируемых на базе создаваемых сервисов, — это один из способов найти адрес необходимого сервиса, что кратко описано в документации K8s.
Один из самых очевидных способов закрыть вопрос — просто сменить имя сервиса в Kubernetes на что-то более явное (а главное — отличное от лаконичного kafka).
Пробуем, запускаем:
$ kubectl -n sentry logs sentry-kafka-0
===> ENV Variables ...
...
SENTRY_KAFKA_PORT=tcp://192.168.224.150:9092
...
===> Configuring ...
===> Running preflight checks ...
===> Check if /var/lib/kafka/data is writable ...
Поздравляем! Вы великолепны!
История №2. Как скромные 100 байт стали причиной больших проблем
Мы любим ClickHouse и используем эту БД во многих проектах как основную базу для сбора статистики. А еще мы храним там логи K8s-кластеров, что очень удобно и эффективно — для этого даже создали специализированный инструмент loghouse. Так что нас не удивишь тем, что на практике могут периодически возникают аварии, связанные с ClickHouse, причем разной степени тяжести…, но этот случай — особенный.
У нас в обслуживании уже много лет есть кластер ClickHouse довольно внушительных размеров: 5 шардов, 10 железных узлов по 45 Тб данных на каждой. В кластере много replicated-таблиц, а обслуживает репликацию кластер ZooKeeper из 3 узлов на виртуальных машинах.
Однажды ночью намертво завис один из гипервизоров, на которых запущены виртуалки ZooKeeper«а. Было принято решение перезагрузить гипервизор, после чего кластер ZK потерял целостность, перестал собираться и обслуживать ClickHouse. Первая мысль — «что-то побилось», поэтому возникла необходимость восстановить метаданные из снапшота.
Сказано — сделано! Однако ZooKeeper при попытке собраться, выбрать лидера и разлить снапшот начинает испытывать проблемы:
2020-07-03 18:19:50,681 [myid:2] - WARN [QuorumPeer[myid=2](plain=[0:0:0:0:0:0:0:0]:2181)(secure=disabled):Follower@129] - Exception when following the leader
java.net.SocketTimeoutException: Read timed out
....
Если пробуем запускать без снапшота и создавать таблички в ClickHouse, то ситуация не лучше:
CREATE TABLE ctest.stor1 (`date` Date, `created` DateTime, `value` Int32) ENGINE = ReplicatedMergeTree('/clickhouse/tables/{shard}/stor1', '{replica}', date, value, 8192);
....
Received exception from server (version 19.14.3):
Code: 999. DB::Exception: Received from 127.0.0.1:9000. Coordination::Exception. Coordination::Exception: All connection tries failed while connecting to ZooKeeper. Addresses: 192.168.110.60:2181, 192.168.110.61:2181, 192.168.110.62:2181
....
Code: 209, e.displayText() = DB::NetException: Timeout exceeded while reading from socket (192.168.110.62:2181): while receiving handshake from ZooKeeper (version 19.14.3.3 (official build)), 192.168.110.62:2181
(Connection loss).
Любопытно: ведь мы не меняли никаких настроек… ни на серверах, ни в конфигурации самих CH и ZK. Но косвенно данные проблемы указывают на проблемы с сетью, к тому же, они явно завязаны на ZK.
Не буду вдаваться в излишнюю детализацию всех наших действий, предпринятых для обнаружения источника проблем, — достаточно лишь сказать, что понервничали прилично. Итогом же этих исследований стал… самый обычный MTU!
2: ens3: mtu 1500 qdisc fq_codel state UP group default qlen 1000
link/ether 52:54:00:e5:6d:fc brd ff:ff:ff:ff:ff:ff
inet 192.168.110.60/24 brd 192.168.110.255 scope global ens3
valid_lft forever preferred_lft forever
Всё дело в том, что сеть на виртуалках для ZK создавалась довольно давно — в 2018 году, сразу после выхода Ubuntu 18.04 и тогда был задействован еще не ставший по-настоящему привычным netplan. А он по умолчанию выставляет MTU в 1500 байт. В то же время, как многие знают, значение MTU по умолчанию в Hetzner vSwitch — 1400 байт.
Итог: использование кластера до сих пор не требовало пакетов подобного размера, так что и проблема ни разу не всплывала, а сейчас разница в 100 байт оказалась фатальной. При уменьшении MTU кластер завёлся и вернулся к работе без каких-либо проблем (а мы продолжили устранять последствия).
Бонус!
При восстановлении метаданных в ZK мы пробовали (помимо прочего) вручную пересоздавать таблицы и обнаружили интересную особенность.
Такой формат создания таблицы (когда ключ партиционирования и первичный ключ указываются прямо в секции ENGINE) начиная с 20 версии ClickHouse является устаревшим (deprecated):
CREATE TABLE ctest.stor1foo (`date` Date, `created` DateTime, `value` Int32)
ENGINE = ReplicatedMergeTree('/clickhouse/tables/{shard}/stor1foo', '{replica}', date, value, 8192);
В актуальных версиях ClickHouse правильным является такой вариант:
CREATE TABLE ctest.stor1bar
(
`date` Date,
`created` DateTime,
`value` Int32
) ENGINE = ReplicatedMergeTree('/clickhouse/tables/{shard}/stor1bar', '{replica}')
PARTITION BY date
ORDER BY value
SETTINGS index_granularity = 8192
Приглядитесь: по сути оба варианта делают совершенно идентичную работу и создают одинаковые таблицы с одинаковыми параметрами. Но давайте посмотрим, какие метаданные генерируют эти команды:
[zk: localhost:2181(CONNECTED) 5] get /clickhouse/tables/1/stor1foo/metadata
metadata format version: 1
date column: date
sampling expression:
index granularity: 8192
mode: 0
sign column:
primary key: value
granularity bytes: 10485760
[zk: localhost:2181(CONNECTED) 6] get /clickhouse/tables/1/stor1bar/metadata
metadata format version: 1
date column:
sampling expression:
index granularity: 8192
mode: 0
sign column:
primary key: value
data format version: 1
partition key: date
granularity bytes: 10485760
На выходе есть различие в полях date column и partition key, хотя входные данные, на первый взгляд, одинаковы, что делает несовместимыми метаданные и таблицы в CH, созданные с разным форматированием запроса.
История №3. Как был перегружен K8s-кластер…, а на самом деле — перегрет
Однажды от клиента поступило обращение о сбоях в работе одного из сервисов. При осмотре pod«ов этого сервиса выяснилось, что pod«ы периодически перезапускаются и толком не работают.
Сервис был запущен на нескольких узлах K8s, нагрузка на CPU у которых была просто колоссальной. Рост нагрузки произошел на разных узлах не одновременно, но очень близко друг к другу по времени. Ситуация была столь плоха, что в какой-то момент kubelet попросту перестал отвечать.
При этом на проблемных узлах потребление процессора ресурсами кластера было не очень велико: львиная доля приходилась на kidle_inj, т.е. ядро постоянно запускало idle-процесс.
$ dmesg -T | grep intel_powercl
[Sat Jun 13 06:29:00 2020] intel_powerclamp: Start idle injection to reduce power
[Sat Jun 13 06:29:02 2020] intel_powerclamp: Stop forced idle injection
[Sat Jun 13 06:29:05 2020] intel_powerclamp: Start idle injection to reduce power
[Sat Jun 13 06:29:07 2020] intel_powerclamp: Stop forced idle injection
[Sat Jun 13 06:29:08 2020] intel_powerclamp: Start idle injection to reduce power
Этот кластер построен на bare metal, т.е. железных узлах. Возник законный вопрос: что с их температурой?
$ sensors
coretemp-isa-0000
Adapter: ISA adapter
Package id 0: +92.0°C (high = +80.0°C, crit = +100.0°C)
Core 0: +90.0°C (high = +80.0°C, crit = +100.0°C)
Core 1: +91.0°C (high = +80.0°C, crit = +100.0°C)
Core 2: +92.0°C (high = +80.0°C, crit = +100.0°C)
Core 3: +91.0°C (high = +80.0°C, crit = +100.0°C)
90 градусов!
Самое время написать в техподдержку дата-центра с запросом проверить машины, а в то же время искать любые возможности, куда переключить нагрузку.
Ответом техподдержки стало сообщение о необходимости отключения машин на 30 минут для проведения работ. Чтобы согласиться на это, мы отключили (drain«ом) первый проблемный узел. А в результате проведённых операций получили такой ответ ДЦ:
Dear Client,
unfortunately the CPU fan was faulty, we’ve replaced this and started the server again.
Что и требовалось доказать! Дальнейшие шаги понятны: поочередный вывод узлов из кластера и координация наших действий с сотрудниками в ДЦ, меняющими кулеры. Ситуация с нагрузкой буквально на глазах приходит в норму.
История №4. Ода pg_repack для PostgreSQL
Обычно мы не оказываем услуги DBA. Да, мы можем посмотреть на вашу базу, создать пару индексов, оптимизировать запросы. Зачастую такие вещи происходят просто по стечению обстоятельств: заметили какую-то странность, пошли смотреть внимательно и что-то нашли (всегда можно что-то найти, если смотреть внимательно).
Однажды наш дежурный заметил рост долгих транзакций на базе клиента. Точнее, его зафиксировала система мониторинга: плановая задача очистки неактуальных данных из базы стала занимать всё больше времени, из-за чего попала под триггер долгих транзакций.
Несмотря на предпринятый простой шаг для решения первоначальной проблемы, о которой сообщил мониторинг, стало ясно, что требуется более внимательный анализ ситуации.
Для этого мы с помощью модуля pgstattuple оценили фрагментированность таблиц запросами:
SELECT schemaname,
tablename,
dead_tuple_count(stats) AS dead_tuples,
pg_size_pretty(dead_tuple_len(stats)) AS dead_space,
pg_size_pretty(free_space(stats)) AS free_space,
last_autovacuum,
last_autoanalyze
FROM
(SELECT pgt.schemaname AS schemaname,
pgt.tablename AS tablename,
pgstattuple(pgt.schemaname || '.' || pgt.tablename)
AS stats,
uts.last_autovacuum AS last_autovacuum,
uts.last_autoanalyze AS last_autoanalyze
FROM pg_tables AS pgt
LEFT JOIN pg_stat_user_tables
AS uts
ON pgt.schemaname = uts.schemaname
AND pgt.tablename = uts.relname
WHERE pgt.schemaname NOT IN ('repack','pg_catalog')) AS r
ORDER BY dead_tuples DESC;
… и фрагментированность индексов:
SELECT schemaname,
indexname,
tablename,
dead_tuple_count(stats) AS dead_tuples,
pg_size_pretty(dead_tuple_len(stats)) AS dead_space,
pg_size_pretty(free_space(stats)) AS free_space
FROM
(SELECT pgt.schemaname AS schemaname,
pgt.indexname AS indexname,
pgt.tablename AS tablename,
pgstattuple(pgt.schemaname || '.' || pgt.indexname) AS stats
FROM pg_indexes AS pgt
WHERE pgt.schemaname NOT IN ('repack',
'pg_catalog')
AND pgt.indexname NOT IN ('some',
'important',
'triggers')) AS r
ORDER BY dead_tuples DESC;
В процессе этого исследования были выявлены фрагментированные таблицы и индексы в огромном количестве. Решение — выполнить pg_repack и параллельно зачистить ряд дублирующихся индексов.
Операция repack«а на БД размером 620 Гб заняла целую ночь и утро. Результатом стал выигрыш около 150 Гб дискового пространства и сопутствующее «причесывание» базы в сочетании с небольшим ростом производительности. Ближайший план — миграция с PostgreSQL v11 на v12, так как в нём применены техники для снижения фрагментирования данных, а значит — проблема станет меньше нам мешать.
Вывод банален: следите за базами, оптимизируйте с умом и не превращайте их в лапшу, наполненную бесполезными индексами.
Заключение
Даже привычные инструменты зачастую могут преподносить сюрпризы (как приятные, так и не очень), что, несомненно, делает нашу и без того насыщенную работу еще интереснее. А что подобного случалось у вас? У нас же историй еще много, так что до встречи в следующей части!
P.S.
Читайте также в нашем блоге:
