company_banner

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


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

    Флант
    DevOps-as-a-Service, Kubernetes, обслуживание 24×7

    Комментарии 6

      +4

      Спасибо! Очень занятно!
      Про кафку причину я угадал (сервис дискавери через ENV).
      Про ZK:


      Однажды ночью намертво завис один из гипервизоров, на которых запущены виртуалки ZooKeeper’а.

      Ну, е-мае, зачем все яйца в одну корзину складывать? Как вообще с этим боретесь (все члены кластера на одном гипере или все реплики сервиса на одной кубера)?


      Ну, и КДПВ как всегда топчик )))

        +7
        На самом деле яйца не в одной корзине: виртуалки зукипера на разных серверах, в кубах — pod anti-affinity. Но проблема с MTU, которую не отловили сразу, привела к полной недоступности ZK. В статье еще забыт момент о том, что в конфигах netplan был указан нужный MTU, однако он не применялся.
        0
        а можно немного деталей про перегрев процессора на баре-метал?
        >> поочередный вывод узлов из кластера и координация наших действий с сотрудниками в ДЦ, меняющими кулеры
        это какой то блейд был? и
          +4
          к несчастью, нет. это были чудесные сервера одного немецкого дата-центра, который мы не будем называть.
            0
            то есть получается у них массово пошли на выход куллеры. мдя, красавцы они)
              0
              ну мы решили, что дело было в конкретном машинном зале, поскольку все железки в одной стойке, естественно точно нам никто не подтвердил. может быть кондиционер вышел из строя, может быть просто строительные работы или что-то такое рядом.

        Только полноправные пользователи могут оставлять комментарии. Войдите, пожалуйста.

        Самое читаемое