Практические истории из наших 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 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.


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

  • «6 практических историй из наших SRE-будней»;
  • «Из жизни с Kubernetes: Как мы выносили СУБД (и не только) из review-окружений в статическое»;
  • «Из жизни с Kubernetes: Как HTTP-сервер испанцев не жаловал»;
  • «6 занимательных системных багов при эксплуатации Kubernetes [и их решение]».
Источник: https://habr.com/ru/company/flant/blog/510486/


Интересные статьи

Интересные статьи

Это вторая часть статьи, посвященной автоматизации системного тестирования на основе виртуальных машин. Первую часть можно найти здесь. В этой части статьи мы будем использовать навы...
В прошлых частях цикла «Введение в SSD» мы рассказали про историю появления дисков и интерфейсов взаимодействия с накопителями. Третья часть познакомит читателя с современными форм-факторами ...
Всем привет! Если вы слышали о Blazor, но до сих пор не понимаете, что это такое. То вы по адресу. Это первая статья из цикла 12 статей, которая проведет вас через все круги ада весь процесс созд...
Это третья, заключительная часть из цикла. В предыдущей статье мы подробно рассказали об УСН, патенте и налоге для самозанятых. В этой части рассчитаем налоговую нагрузку для ИП с доходом 100, ...
На Хабре сегодня уже звучали хэллоуинские байки. А как насчет конкурса на самую страшную историю? Пускай она начинается так: Пустой ночной офис отзывался холодом. Шум серверов и ветер в...