21.07.2020 07:38
sibilek 6 3300 Источник


Утекло уже немало воды с момента публикации нашего последнего очерка об интересных случаях из практики обслуживания 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 database.storage1 (`date` Date, `created` DateTime, `value` Int32) ENGINE = ReplicatedMergeTree('/clickhouse/tables/{shard}/storage1', '{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.0.60:2181, 192.168.0.61:2181, 192.168.0.62:2181
....
Code: 209, e.displayText() = DB::NetException: Timeout exceeded while reading from socket (192.168.0.62:2181): while receiving handshake from ZooKeeper (version 19.14.3.3 (official build)), 192.168.0.62:2181
(Connection loss).

Любопытно: ведь мы не меняли никаких настроек… ни на серверах, ни в конфигурации самих CH и ZK. Но косвенно данные проблемы указывают на проблемы с сетью, к тому же, они явно завязаны на ZK.

Не буду вдаваться в излишнюю детализацию всех наших действий, предпринятых для обнаружения источника проблем, — достаточно лишь сказать, что понервничали прилично. Итогом же этих исследований стал… самый обычный MTU!

2: ens3: <BROADCAST,MULTICAST,UP,LOWER_UP> 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.0.60/24 brd 192.168.0.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 database.storage1foo (`date` Date, `created` DateTime, `value` Int32)
ENGINE = ReplicatedMergeTree('/clickhouse/tables/{shard}/storage1foo', '{replica}', date, value, 8192);

В актуальных версиях ClickHouse правильным является такой вариант:

CREATE TABLE database.storage1bar
(
 `date` Date,
 `created` DateTime,
 `value` Int32
) ENGINE = ReplicatedMergeTree('/clickhouse/tables/{shard}/storage1bar', '{replica}')
PARTITION BY date
ORDER BY value
SETTINGS index_granularity = 8192

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

[zk: localhost:2181(CONNECTED) 5] get /clickhouse/tables/1/storage1foo/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/storage1bar/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.


Читайте также в нашем блоге: