Привет, Хабр! Меня зовут Станислав Егоркин, я инженер юнита IaaS департамента разработки Infrastructure в Авито. Эта статья посвящена обнаружению деградаций на нодах в кластерах Kubernetes. Я расскажу про инструмент, который мы используем, а также покажу дашборд, где мы наблюдаем за состоянием всех наших нод.

Причины деградаций на нодах

Инфраструктура Авито — это тысячи bare-metal серверов, большая часть из которых объединена в десятки Kubernetes-кластеров. Понятно, что в таких масштабах отказ отдельных кубонод — событие регулярное. Причины могут быть разные: от поломки планки памяти до возникновения проблем с container runtime.

Хорошо, если нода отказала полностью, тогда Kubernetes сам обработает отказ, и рабочая нагрузка пострадает минимально. Хуже, когда деградация частичная. В этом случае нода может долго находиться в плохом состоянии, заставляя «страдать» все сервисы, которые оказались запущены на ней.

Обычно события в этом случае развиваются следующим образом: кто-то из разработчиков замечает деградацию своего микросервиса, локализовывает ее до ноды и приходит к нам. Мы диагностируем и прочиниваем ноду. Однако некоторые проблемы встречались на разных нодах снова и снова. И каждый раз они требовали нашего вмешательства.

Показательный пример такого рода проблем – нарушение синка kubelet с docker. Если kubelet не может выполнить SyncLoop() в течение трех минут, он пишет в лог Pleg is not healthy. На практике это – симптом частичной деградации.

По нашим наблюдениям, появление в логах нескольких сообщений такого вида означает, что скоро на ноду придут жаловаться. К сожалению, эта проблема не имеет постоянного решения с теми версиями кубовых компонентов, которые мы используем. Но есть достаточно хорошее временное решение – необходимо выполнить systemctl restart docker. Это операция не затрагивает рабочую нагрузку и после ее выполнения проблема на ноде не воспроизводится совсем, либо воспроизводится очень нескоро. 

К слову, точно такое же решение автоматически применялось в кластерах Google Kubernetes Engine. Нам же это приходилось делать вручную.

И мы, разумеется, тоже задумались об автоматизации. В идеале мы хотели получить систему, в которой все известные нам проблемы обнаруживаются и устраняются автоматически.

Последние полгода я занимался внедрением механик Auto Healing. Сейчас они работают во всех prod- и staging-кластерах Авито. Эта статья посвящена первому этапу Auto Healing — автоматическому обнаружению деградаций.

Выбор инструмента 

До начала работы над проектом для обнаружением проблем на нодах использовался самописный сервис k8s-node-acceptance. Это был код на Python, который с заданными интервалами запускал проверки доступности docker registry, статуса инфраструктурных сервисов на ноде и так далее. Результаты записывались в node conditions рядом с дефолтными кондишенами Ready, DiskPressure и т.д. Он работал неплохо, но имел несколько недостатков:

• не отдавал метрик;

• потреблял довольно много ресурсов;

• сильно нагружал kube-apiserver, поскольку node conditions обновлялись после запуска каждой проверки.

После небольшого ресерча я предложил заменить его на Node Problem Detector, часть проекта Kubernetes. Он используется по умолчанию в кластерах Google Kubernetes Engine и Amazon Elastic Kubernetes Service. Сервис написан на Go, отдает метрики, умеет парсить логи, содержит множество проверок «из коробки» и легко расширяем. Как показал опыт, это был хороший выбор. 

Node Problem Detector 

До того, как внедрять NPD, нужно было принять несколько принципиальных решений. Первое — запускать его в виде пода или в качестве systemd-юнита. У каждого подхода есть свои плюсы и минусы.

Запуск в поде удобнее для целей обновления и мониторинга состояния самого NPD. Это гораздо более гибкий подход, чем запекание его в образ. Кроме того, так мы можем писать проверки в отношении pod network. Однако вероятность того, что под с NPD не стартует, выше, чем если бы он был демоном. Кроме того, это лишает возможности использовать healthchecker — утилиты NPD, которая проверяет здоровье systemd-юнитов kubelet и docker (или по крайней мере требует прокидывания в под высоких привилегий). Взвесив все «за» и «против», я остановился на первом варианте.

Мы используем нативный NPD с кастомными проверками. Код лежит во внутреннем репозитории и собирается CI/CD в минималистичный docker image. Затем образ доставляется во все кластеры с помощью Application Set для ArgoCD.

Принцип работы NPD очень прост: ему передаются пути до манифестов проверок, в которых описан их тип, интервал запуска и путь до логов (понимает kmsg, journal и логи в произвольном формате) либо до скрипта с кастомной проверкой.

Пример манифеста проверки:

{
  "plugin": "custom",
  "pluginConfig": {
      "invoke_interval": "1m",
      "timeout": "1m",
      "max_output_length": 80,
      "concurrency": 1,
      "skip_initial_status": true
  },
  "source": "journalctl-custom-monitor",
  "metricsReporting": true,
  "conditions": [
      {
      "type": "PLEGisUnhealthy",
      "reason": "PLEGisHealthy",
      "message": "PLEG is functioning properly"
      }
  ],
  "rules": [
      {
      "type": "permanent",
      "condition": "PLEGisUnhealthy",
      "reason": "PLEGisUnhealthy",
      // Here we use a custom alternative to logcounter that comes with NPD
      // as our version runs much faster on large logs
      "path": "/home/kubernetes/bin/journalcounter",
      "args": [
          "--identifier=kubelet",
          "--lookback=10m",
          "--count=3",
          "--pattern=PLEG is not healthy: pleg was last seen active"
      ],
      "timeout": "1m"
      }
  ]
}

Скрипты могут быть написаны на любом языке, единственное требование — нулевой код возврата в случае успешной проверки и ненулевой — в случае обнаружения проблем. Возник соблазн просто перенести часть проверок из k8s-node-acceptance, оформив их в виде отдельных скриптов на Python. Это оказалось не очень хорошей идеей. 

NPD запускает проверки независимо одну от другой, а значит, что для каждой из них загружается свой интерпретатор Python. Работали они со скрипом, и я переписал проверки на Go, добавив от себя несколько новых. Для сравнения: с проверками на Python NPD не всегда укладывался в лимит 500m по cpu, а с проверками на Go редко потребляет больше 30m.

Ниже — два примера скриптов, которые мы используем.

Простейшая проверка, определяющая возможность установления TCP-соединений до выбранных хостов:

package main

import (
    "fmt"
    "net"
    "os"
    "strings"
    "time"
)

const TIMEOUT = 2 * time.Second

func checkTCPConnect(endpoints []string) (bool, string) {
    errors := 0

    for _, endpoint := range endpoints {
        parts := strings.Split(endpoint, ":")
        if len(parts) != 2 {
            return false, fmt.Sprintf("INVALID ENDPOINT FORMAT: %s", endpoint)
        }

        conn, err := net.DialTimeout("tcp", endpoint, TIMEOUT)
        if err != nil {
            errors++
            continue
        }
        defer conn.Close()
    }

    endpointString := strings.Join(endpoints, ", ")
    if errors == len(endpoints) {
        // We use uppercase writing to make errors more noticeable among node conditions
        return false, fmt.Sprintf("TIMEOUT TO ENDPOINTS: %s", strings.ToUpper(endpointString))
    }
    return true, fmt.Sprintf("connected to at least one endpoint: %s", endpointString)
}

func main() {
    if len(os.Args) < 2 {
        fmt.Println("Usage: tcp-connect address1:port1 address2:port2 ...")
        os.Exit(1)
    }
    endpoints := os.Args[1:]
    result, msg := checkTCPConnect(endpoints)
    fmt.Println(msg)
    if !result {
        os.Exit(1)
    }
}

Чуть более сложный скрипт, который обращается к сокету bird и проверяет, что у calico есть по крайней мере один активный BGP-peer. Большая часть кода заимствована из calicoctl, нативной утилиты calico (по сути мы делаем в скрипте то же самое, что при выполнении calicoctl node status):

package main

import (
    "bufio"
    "errors"
    "fmt"
    "net"
    "os"
    "reflect"
    "regexp"
    "strings"
    "time"

    log "github.com/sirupsen/logrus"
)

// Timeout for querying BIRD.
var birdTimeOut = 4 * time.Second

// Expected BIRD protocol table columns
var birdExpectedHeadings = []string{"name", "proto", "table", "state", "since", "info"}

// bgpPeer is a structure containing details about a BGP peer
type bgpPeer struct {
    PeerIP   string
    PeerType string
    State    string
    Since    string
    BGPState string
    Info     string
}

// Check for Word_<IP> where every octate is separated by "_", regardless of IP protocols
// Example match: "Mesh_192_168_56_101" or "Mesh_fd80_24e2_f998_72d7__2"
var bgpPeerRegex = regexp.MustCompile(`^(Global|Node|Mesh)_(.+)$`)

// Mapping the BIRD/GoBGP type extracted from the peer name to the display type
var bgpTypeMap = map[string]string{
    "Global": "global",
    "Mesh":   "node-to-node mesh",
    "Node":   "node specific",
}

func checkBGPPeers() (bool, string) {
    // Show debug messages
    // log.SetLevel(log.DebugLevel)

    // Try connecting to the bird socket in `/var/run/calico/` first to get the data
    c, err := net.Dial("unix", "/var/run/calico/bird.ctl")
    if err != nil {
        // If that fails, try connecting to bird socket in `/var/run/bird` (which is the
        // default socket location for bird install) for non-containerized installs
        c, err = net.Dial("unix", "/var/run/bird/bird.ctl")
        if err != nil {
            return false, "ERROR: UNABLE TO OPEN BIRD SOCKET"
        }
    }
    defer c.Close()

    // To query the current state of the BGP peers, we connect to the BIRD
    // socket and send a "show protocols" message. BIRD responds with
    // peer data in a table format
    //
    // Send the request
    _, err = c.Write([]byte("show protocols\n"))
    if err != nil {
        return false, "UNABLE TO WRITE TO BIRD SOCKET"
    }

    // Scan the output and collect parsed BGP peers
    peers, err := scanBIRDPeers(c)

    if err != nil {
        // If "read unix @->/var/run/calico/bird.ctl: i/o timeout" then skip check
        // This error usually means that it is very high LA on node
        if netErr, ok := err.(net.Error); ok && netErr.Timeout() {
            return true, fmt.Sprintf("Skipping because of: %v", err)
        } else {
            return false, fmt.Sprintf("ERROR: %v", err)
        }
    }

    // If no peers were returned then just print a message
    if len(peers) == 0 {
        return false, "CALICO HAS NO BGP PEERS"
    }

    for _, peer := range peers {
        log.Debugf(peer.PeerIP, peer.BGPState)
        if peer.BGPState == "Established" {
            return true, "calico bird have at least one peer with established connection"
        }
    }

    return false, "NO CONNECTION TO BGP PEERS"

}

func scanBIRDPeers(conn net.Conn) ([]bgpPeer, error) {
    ipSep := "."

    // The following is sample output from BIRD
    //
    //  0001 BIRD 1.5.0 ready.
    //  2002-name     proto    table    state  since       info
    //  1002-kernel1  Kernel   master   up     2016-11-21
    //       device1  Device   master   up     2016-11-21
    //       direct1  Direct   master   up     2016-11-21
    //       Mesh_172_17_8_102 BGP      master   up     2016-11-21  Established
    //  0000
    scanner := bufio.NewScanner(conn)
    peers := []bgpPeer{}

    // Set a time-out for reading from the socket connection
    err := conn.SetReadDeadline(time.Now().Add(birdTimeOut))
    if err != nil {
        return nil, errors.New("failed to set time-out")
    }

    for scanner.Scan() {
        // Process the next line that has been read by the scanner
        str := scanner.Text()

        log.Debug(str)

        if strings.HasPrefix(str, "0000") {
            // "0000" means end of data
            break
        } else if strings.HasPrefix(str, "0001") {
            // "0001" code means BIRD is ready
        } else if strings.HasPrefix(str, "2002") {
            // "2002" code means start of headings
            f := strings.Fields(str[5:])
            if !reflect.DeepEqual(f, birdExpectedHeadings) {
                return nil, errors.New("unknown BIRD table output format")
            }
        } else if strings.HasPrefix(str, "1002") {
            // "1002" code means first row of data
            peer := bgpPeer{}
            if peer.unmarshalBIRD(str[5:], ipSep) {
                peers = append(peers, peer)
            }
        } else if strings.HasPrefix(str, " ") {
            // Row starting with a " " is another row of data
            peer := bgpPeer{}
            if peer.unmarshalBIRD(str[1:], ipSep) {
                peers = append(peers, peer)
            }
        } else {
            // Format of row is unexpected
            return nil, errors.New("unexpected output line from BIRD")
        }

        // Before reading the next line, adjust the time-out for
        // reading from the socket connection
        err = conn.SetReadDeadline(time.Now().Add(birdTimeOut))
        if err != nil {
            return nil, errors.New("failed to adjust time-out")
        }
    }

    return peers, scanner.Err()
}

// Unmarshal a peer from a line in the BIRD protocol output. Returns true if
// successful, false otherwise
func (b *bgpPeer) unmarshalBIRD(line, ipSep string) bool {
    columns := strings.Fields(line)
    if len(columns) < 6 {
        log.Debug("Not a valid line: fewer than 6 columns")
        return false
    }
    if columns[1] != "BGP" {
        log.Debug("Not a valid line: protocol is not BGP")
        return false
    }

    // Check the name of the peer is of the correct format.  This regex
    // returns two components:
    // -  A type (Global|Node|Mesh) which we can map to a display type
    // -  An IP address (with _ separating the octets)
    sm := bgpPeerRegex.FindStringSubmatch(columns[0])
    if len(sm) != 3 {
        log.Debugf("Not a valid line: peer name '%s' is not correct format", columns[0])
        return false
    }
    var ok bool
    b.PeerIP = strings.Replace(sm[2], "_", ipSep, -1)
    if b.PeerType, ok = bgpTypeMap[sm[1]]; !ok {
        log.Debugf("Not a valid line: peer type '%s' is not recognized", sm[1])
        return false
    }

    // Store remaining columns (piecing back together the info string)
    b.State = columns[3]
    b.Since = columns[4]
    b.BGPState = columns[5]
    if len(columns) > 6 {
        b.Info = strings.Join(columns[6:], " ")
    }

    return true
}

func main() {
    var message string
    var result bool

    result, message = checkBGPPeers()

    fmt.Println(message)

    if !result {
        os.Exit(1)
    }
}

Кроме того, мы пользуемся двумя наборами проверок, которые идут в комплекте с NPD: docker-monitor и kernel-monitor. Они парсят соответственно journal и kmsg на предмет перемонтирования файловой системы в read-only, ошибок памяти и так далее.

Виды проверок NPD

NPD умеет проводить два типа проверок: permanent и temporary. Результаты прохождения первых отражаются в node conditions и метрике problem_gauge, вторых — только в метрике problem_counter. Почти все наши проверки относятся к первому типу, поскольку: 

• механики Auto Healing реагируют именно на conditions; 

• если на ноде есть какая-то деградация, мы хотим видеть ее, выполнив kubectl describe node.

При проектировании проверок я исходил из того, что они должны отвечать одному из следующих требований: либо однозначно детектировать известную нам проблему, либо давать ясное представление о каком-либо состоянии.

Примером проверки, однозначного детектирующей известную проблему, служит PLEGisUnhealthy. Она написана так, чтобы срабатывать только в случае возникновения проблемы, которая требует вмешательства. Именно поэтому мы ищем в логах паттерн PLEG is not healthy: pleg was last seen active: pleg was last seen active, а не просто PLEG is not healthy. Последний паттерн сработал бы и при следующей записи в логах: 

skipping pod synchronization - [container runtime status check may not have completed yet., PLEG is not healthy: pleg has yet to be successful.], 

А она, как правило, не свидетельствует о проблеме. Кроме того, эта проверка проваливается, только если мы находим не менее трех вхождений паттерна за последние 10 минут.

Примером проверки, дающей ясное представление о состоянии, может быть проверка RegistryIsNotAvailable. Она проверяет доступность с ноды docker registry. Если проверка проваливается, однозначно мы можем сказать только то, что registry с ноды недоступен. Если вместе с ней проваливаются другие сетевые проверки, то проблема скорее всего в сетевой связности ноды. 

Если же RegistryIsNotAvailable проваливается одновременно на многих нодах, то мы можем предположить, что проблема в самом registry или сетевой связности до него. Цель подобных проверок – дать нам точный ответ на простой вопрос, например, «доступен ли registry?». Иногда они здорово помогают в диагностике, но их не стоит использовать для Auto Healing, поскольку провал таких проверок может происходить по разным причинам. 

Улучшение observability 

До внедрения NPD у нас не было дашборда, позволяющего наблюдать за проблемами на нодах сразу во всех кластерах. Можно было использовать метрики по node conditions, но это работало не слишком хорошо. Информация шла через kube-apiserver с некоторым лагом, а promql-запросы были не слишком отзывчивы. С метриками от NPD все работает очень быстро, и если NPD обнаружил какую-либо проблему, то мы узнаем об этом с минимальной задержкой.

Я подумал: если обогатить эти метрики другой полезной информацией, можно создать дашборд, который дает достаточно полное представление о том, что происходит со всеми нашими кубонодами. Так появился инструмент, который сегодня служит для нашей команды основным средством observability в отношении кубонод.

Дашборд состоит из нескольких разделов. Первый дает представление о текущем состоянии нод.

На нём отображаются: 

• общее количество нод, на которых обнаружены проблемы;

• общее число различных типов обнаруженных проблем;

• таблица с типами проблем и именами кластеров, в которых они обнаружены;

• таблица с проблемными нодами и следующей информацией о них:

  • проваленные проверки NPD и kubelet,

  • статус ноды (Ready/NotReady/Unknown),

  • флапает ли нода (переходила ли из состояния Ready в NotReady и обратно за последние 20 минут),

  • закордонена ли нода.

Три верхних панели позволяют быстро понять, когда проблема становится массовой. В этих редких случаях первый счётчик, находящийся слева, как правило выходит в красную зону, а второй — нет, поскольку на всех нодах детектится одна и та же проблема. В таблице справа видно, какая проверка и на скольких нодах провалена. При большом количестве нод с одинаковой проблемой счетчик в правой части таблицы становится красным.

Ниже находится второй раздел. Он открывается большой панелью с историей состояний. Нода попадает на эту панель, если в выбранном интервале времени она переходила в NotReady либо попадала на радары NPD.

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

• красный означает критические проблемы вроде Kernel Deadlock или переход ноды в NotReady;

• синий и его оттенки — разные виды сетевых проблем;

• фиолетовый — истекающие сертификаты и тому подобное; 

• желтый — слишком высокий load average.

В случае, если провалено сразу несколько проверок, цвет будет определен по наиболее критичной из них. Панель, кстати, сделана с помощью плагина Statusmap, который написали ребята из Флант. К сожалению, они давно его не поддерживают. Плагин имеет пару неприятных багов, но в целом работает нормально.

Ниже расположена еще одна панель, на которой отображается количество проблем всех типов в каждом из кластеров. Так она выглядит обычно:

А так на ней выглядит инцидент:

На графике виден сетевой сбой, который вызвал провал нескольких проверок на всех нодах в нескольких кластерах. В этом случае дашборд не дал возможность установить причину, но позволил сразу локализовать проблему до конкретных кластеров.

Под этой панелью есть еще несколько разделов с разного рода полезной информацией: 

• предпринятые попытки Auto Healing;

• список закордоненных нод;

• состояние NPD на нодах (запущен ли, обновлен ли до последней версии) и так далее.

Польза и развитие

В ходе инцидентов NPD уже пару раз сыграл важную роль. У нас настроен алерт, который срабатывает, если проверка одновременно проваливается более, чем на 20% нод. Благодаря ему мы узнавали об инцидентах за некоторое время до поступления обращений от других команд.

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

Дашборд оказался полезен и в менее драматичных ситуациях. Теперь, если мы хотим проверить состояние конкретной ноды, то в первую очередь смотрим, появлялась ли она на радарах NPD.

Разумеется, все описанные механики мы будем улучшать. Инфраструктура быстро развивается: проблемы, которые регулярно встречаются сегодня, перестанут возникать завтра, но появятся другие,  и они потребуют новых проверок для NPD. Впрочем, трудозатраты на такую поддержку невелики.

Дашборд также постепенно развивается. Например, теперь на главной панели со списком проблемных нод видно, когда в отношении какой-либо из них применяются механики Auto Healing. В будущем туда могут быть добавлены проблемы, однозначно детектируемые по метрикам, что позволит вывести observability нод в кластере на еще более высокий уровень.

Итоги

В этой статье мы обсудили механики обнаружения деградаций посредством использования инструмента Node Problem Detector, а также рассмотрели возможность расширения стандартного набора проверок. Помимо этого мы оценили пользу инструмента в сценариях повышения observability кластеров k8s.

Про обнаружение деградаций на этом все. Если вам интересно обсудить детали реализации — пожалуйста, задавайте вопросы в комментариях. Спасибо за уделенное статье время!

Подписывайтесь на канал AvitoTech в Telegram, там мы рассказываем больше о профессиональном опыте наших инженеров, проектах и работе в Авито, а также анонсируем митапы и статьи.