6 интересни системни грешки при експлоатация на Kubernetes [и тяхното решение]

През годините на експлоатация на Kubernetes в продукция, натрупахме немалко интересни истории, как бъгове в различни системни компоненти водят до неприятни и/или неясни последствия, влияещи на работата на контейнерите и pod-овете. В тази статия направихме подборка на някои от най-честите или интересни случаи. Дори ако никога не ви се случи да се сблъскате с подобни ситуации, четенето на такива кратки детективи — особено „от първа ръка“ — винаги е интересно, нали?

История 1. Supercronic и зависващ Docker

На един от кластерите периодично получавахме „зависнал“ Docker, което пречеше на нормалното функциониране на кластера. При това в логовете на Docker наблюдавахме следното:

level=error msg="containerd: start init process" error="exit status 2: "runtime/cgo: pthread_create failed: No space left on device
SIGABRT: abort
PC=0x7f31b811a428 m=0

goroutine 0 [idle]:

goroutine 1 [running]:
runtime.systemstack_switch() /usr/local/go/src/runtime/asm_amd64.s:252 fp=0xc420026768 sp=0xc420026760
runtime.main() /usr/local/go/src/runtime/proc.go:127 +0x6c fp=0xc4200267c0 sp=0xc420026768
runtime.goexit() /usr/local/go/src/runtime/asm_amd64.s:2086 +0x1 fp=0xc4200267c8 sp=0xc4200267c0

goroutine 17 [syscall, locked to thread]:
runtime.goexit() /usr/local/go/src/runtime/asm_amd64.s:2086 +0x1

…

В тази грешка най-много ни интересува съобщението: pthread_create failed: No space left on device. Бързото проучване документацията обясни, че Docker не може да форкне процес, поради което периодично „зависваше“.

В мониторинга на събитията се получава следната картина:

Подобна ситуация се наблюдава и на другите възли:

На тези същите възли виждаме:

root@kube-node-1 ~ # ps auxfww | grep curl -c
19782
root@kube-node-1 ~ # ps auxfww | grep curl | head
root     16688  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root     17398  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root     16852  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root      9473  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root      4664  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root     30571  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root     24113  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root     16475  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root      7176  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] 
root      1090  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl]

Оказа се, че такова поведение е последица от работата на pod-а с supercronic (инструмент на Go, който използваме за стартиране на cron задачи в pod-овете):

 _ docker-containerd-shim 833b60bb9ff4c669bb413b898a5fd142a57a21695e5dc42684235df907825567 /var/run/docker/libcontainerd/833b60bb9ff4c669bb413b898a5fd142a57a21695e5dc42684235df907825567 docker-runc
|   _ /usr/local/bin/supercronic -json /crontabs/cron
|       _ /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /dev/stderr --port /run/newrelic.sock --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true
|       |   _ /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /dev/stderr --port /run/newrelic.sock --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true -no-pidfile
|       _ [newrelic-daemon] 
|       _ [curl] 
|       _ [curl] 
|       _ [curl] 
...

Проблемата е следната: когато задачата се стартира в supercronic, процесът, произхождащ от него, не може да завърши коректно, превръщайки се в зомби.

Забележка: По-точно, процесите се създават от cron задачи, но supercronic не е система за инициализация и не може да „осинови“ процеси, които са породили неговите деца. При получаване на сигналите SIGHUP или SIGTERM те не се предават на произтичащите процеси, в резултат на което децата остават в зомби статус. Повече информация за всичко това можете да прочетете, например, в такава статия.

Има няколко начина за решаване на проблемите:

1. Като временно решение — увеличете броя на PID-ите в системата по едно и също време:

          /proc/sys/kernel/pid_max (since Linux 2.5.34)
                 This file specifies the value at which PIDs wrap around (i.e., the value in this file is one greater than the maximum PID).  PIDs greater than this  value  are  not  allo‐
                 cated;  thus, the value in this file also acts as a system-wide limit on the total number of processes and threads.  The default value for this file, 32768, results in the
                 same range of PIDs as on earlier kernels

2. Или стартирайте задачите в supercronic не директно, а с помощта на същото tini, което може да завършва процеси коректно и не произвежда зомби.

История 2. «Зомби» при изтриване на cgroup

Kubelet започна да консумира голямо количество CPU:

Това няма да се хареса на никого, затова се въоръжихме perf и започнахме да разследваме проблема. Резултатите от разследването се оказаха следните:

• Kubelet изразходва повече от една трета от процесорното време за извличане на данни за паметта от всички cgroup:

  

• В разпространението на разработчиците на ядрото можете да намерите дискусия за проблема. Накратко, същността е, че различни tmpfs файлове и други подобни не се изтриват напълно от системата при изтриване на cgroup — остават така наречените memcg зомби. Рано или късно те все пак ще бъдат изтрити от page cache, но на сървера има много памет и ядрото не вижда смисъл да харчи време за тяхното изтриване. Затова те продължават да се натрупват. Защо това изобщо се случва? Това е сървър с cron задачи, който постоянно създава нови job’и, а с тях — нови pod’и. По този начин за контейнерите в тях се създават нови cgroup, които скоро се изтриват.
• Защо cAdvisor в kubelet харчи толкова много време? Това е лесно да се види с простото изпълнение time cat /sys/fs/cgroup/memory/memory.stat. Ако на здраво устройство операцията отнема 0,01 секунди, то на проблемния cron02 — 1,2 секунди. Всичко идва от това, че cAdvisor, който много бавно чете данни от sysfs, се опитва да отчете използваната памет и в зомби cgroups.
• За да принудим изтриването на зомбитата, опитахме да почистим кешовете, както препоръчват в LKML: sync; echo 3 > /proc/sys/vm/drop_caches, — но ядрото се оказа по-сложно и заби машината.

Какво да правим? Проблемът се коригира (комит, а описанието вижте в съобщението за издание) чрез актуализиране на ядрото на Linux до версия 4.16.

История 3. Systemd и неговото монтиране

Отново kubelet изразходва твърде много ресурси на някои възли, но този път — вече памет:

Оказа се, че има проблем в systemd, използван в Ubuntu 16.04, и той възниква при управлението на монтажи, които се създават за свързване subPath от ConfigMap или secret. След приключване на работата на pod’а услугата systemd и нейното служебно монтиране остават в системата. С времето те се натрупват в голямо количество. Има дори issues по тази тема:

1. kops #5916;
2. kubernetes #57345.

… в последното от които се споменава за PR в systemd: #7811 (issue в systemd — #7798).

Проблемът вече не съществува в Ubuntu 18.04, но ако искате да продължите да използвате Ubuntu 16.04, може да ви бъде полезно нашето решение по тази тема.

И така, направихме следния DaemonSet:

---
apiVersion: extensions/v1beta1
kind: DaemonSet
metadata:
  labels:
    app: systemd-slices-cleaner
  name: systemd-slices-cleaner
  namespace: kube-system
spec:
  updateStrategy:
    type: RollingUpdate
  selector:
    matchLabels:
      app: systemd-slices-cleaner
  template:
    metadata:
      labels:
        app: systemd-slices-cleaner
    spec:
      containers:
      - command:
        - /usr/local/bin/supercronic
        - -json
        - /app/crontab
        Image: private-registry.org/systemd-slices-cleaner/systemd-slices-cleaner:v0.1.0
        imagePullPolicy: Always
        name: systemd-slices-cleaner
        resources: {}
        securityContext:
          privileged: true
        volumeMounts:
        - name: systemd
          mountPath: /run/systemd/private
        - name: docker
          mountPath: /run/docker.sock
        - name: systemd-etc
          mountPath: /etc/systemd
        - name: systemd-run
          mountPath: /run/systemd/system/
        - name: lsb-release
          mountPath: /etc/lsb-release-host
      imagePullSecrets:
      - name: antiopa-registry
      priorityClassName: cluster-low
      tolerations:
      - operator: Exists
      volumes:
      - name: systemd
        hostPath:
          path: /run/systemd/private
      - name: docker
        hostPath:
          path: /run/docker.sock
      - name: systemd-etc
        hostPath:
          path: /etc/systemd
      - name: systemd-run
        hostPath:
          path: /run/systemd/system/
      - name: lsb-release
        hostPath:
          path: /etc/lsb-release

… и в него се използва следният скрипт:

#!/bin/bash

# we will work only on xenial
hostrelease="/etc/lsb-release-host"
test -f ${hostrelease} && grep xenial ${hostrelease} > /dev/null || exit 0

# sleeping max 30 minutes to dispense load on kube-nodes
sleep $((RANDOM % 1800))

stoppedCount=0
# counting actual subpath units in systemd
countBefore=$(systemctl list-units | grep subpath | grep "run-" | wc -l)
# let's go check each unit
for unit in $(systemctl list-units | grep subpath | grep "run-" | awk '{print $1}'); do
  # finding description file for unit (to find out docker container, who born this unit)
  DropFile=$(systemctl status ${unit} | grep Drop | awk -F': ' '{print $2}')
  # reading uuid for docker container from description file
  DockerContainerId=$(cat ${DropFile}/50-Description.conf | awk '{print $5}' | cut -d/ -f6)
  # checking container status (running or not)
  checkFlag=$(docker ps | grep -c ${DockerContainerId})
  # if container not running, we will stop unit
  if [[ ${checkFlag} -eq 0 ]]; then
    echo "Stopping unit ${unit}"
    # stoping unit in action
    systemctl stop $unit
    # just counter for logs
    ((stoppedCount++))
    # logging current progress
    echo "Stopped ${stoppedCount} systemd units out of ${countBefore}"
  fi
done

… и се стартира на всеки 5 минути с помощта на вече споменатия supercronic. Неговият Dockerfile изглежда така:

FROM ubuntu:16.04
COPY rootfs /
WORKDIR /app
RUN apt-get update && 
    apt-get upgrade -y && 
    apt-get install -y gnupg curl apt-transport-https software-properties-common wget
RUN add-apt-repository "deb [arch=amd64] https://download.docker.com/linux/ubuntu xenial stable" && 
    curl -fsSL https://download.docker.com/linux/ubuntu/gpg | apt-key add - && 
    apt-get update && 
    apt-get install -y docker-ce=17.03.0*
RUN wget https://github.com/aptible/supercronic/releases/download/v0.1.6/supercronic-linux-amd64 -O 
    /usr/local/bin/supercronic && chmod +x /usr/local/bin/supercronic
ENTRYPOINT ["/bin/bash", "-c", "/usr/local/bin/supercronic -json /app/crontab"]

История 4. Конкуренция при планирането на pod-ове

Забелязано е, че: ако на узла се разположи pod и неговият образ се изтегля много дълго, то друг pod, който "попада" на същия узел, просто не започва да изтегля образа на новия pod.. Вместо това той чака, докато се изтегли образа на предишния pod. В резултат, pod, който вече е бил планиран и образът му може да бъде изтеглен само за минута, ще остане за дълго в статус containerCreating.

В събитията ще бъде приблизително следното:

Normal  Pulling    8m    kubelet, ip-10-241-44-128.ap-northeast-1.compute.internal  pulling image "registry.example.com/infra/openvpn/openvpn:master"

Излиза, че един-единствен образ от бавен регистър може да блокира разгръщането на узла.

За съжаление, вариантите за разрешаване на ситуацията не са много:

1. Стремете се да използвате своя Docker Registry директно в кластера или в непосредствена близост с него (например, GitLab Registry, Nexus и т.н.);
2. Използвайте инструменти като kraken.

История 5. Замръзване на възлите при недостиг на памет

При експлоатацията на различни приложения сме наблюдавали случаи, когато възелът напълно спира да бъде достъпен: не отговаря на SSH, всички мониторингови демони прекъсват, а в логовете след това няма (или почти няма) аномални записи.

Ще разкажа в картинки на примера на един възел, където работеше MongoDB.

Така изглежда atop до аварии:

А така — след аварии:

Също така в мониторинга се наблюдава рязък скок, при който възелът спира да бъде достъпен:

По този начин от скрийншотовете е видно, че:

1. Оперативната памет на машината е почти изчерпана;
2. Наблюдава се рязък скок в потреблението на оперативна памет, след което достъпът до цялата машина рязко се прекъсва;
3. На Mongo идва голяма задача, която принуждава СУБД процеса да използва повече памет и активно да чете от диска.

Оказва се, че ако в Linux свърши свободната памет (настъпи memory pressure) и swap не е наличен, то до при идването на OOM killer може да настъпи равновесие между хвърлянето на страници в page cache и writeback-а им обратно на диска. Това се управлява от kswapd, който усърдно освобождава колкото се може повече страници памет за последващо разпределение.

За съжаление, при голямо натоварване на вход/изход в комбинация с малко свободна памет, kswapd става буталото на цялата система, защото от него зависят всичко разпределенията (page faults) на страници памет в системата. Това може да продължи много дълго, ако процесите не желаят да използват повече памет, а са заседнали на самия ръб на OOM-killer-ска бездна.

Имам логичен въпрос: защо OOM killer идва толкова късно? В текущата си итерация OOM killer е крайно глупав: той убива процес само когато провали опит за разпределение на страница памет, т.е. ако page fault се случи с грешка. Това не се случва достатъчно дълго, защото kswapd усърдно освобождава страници памет, сблъсквайки page cache (целият дисков I/O в системата всъщност) обратно на диска. По-подробно, с описание на стъпките, необходими за разрешаване на подобни проблеми в ядрото, може да се прочете тук.

Това поведение трябва да се подобри с ядрото на Linux 4.6+.

История 6. Pod’ов зависят от състоянието на Pending

В някои клъстери, в които действително функционират много pod’ове, започнахме да забелязваме, че голяма част от тях много дълго "виси" в състояние Pending, въпреки че самите Docker контейнери вече са стартирани на възлите и с тях може да се работи ръчно.

Въпреки това в describe няма нищо лошо:

  Type    Reason                  Age                From                     Message
  ----    ------                  ----               ----                     -------
  Normal  Scheduled               1m                 default-scheduler        Успешно назначен sphinx-0 на ss-dev-kub07
  Normal  SuccessfulAttachVolume  1m                 attachdetach-controller  AttachVolume.Attach успя за обем "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normal  SuccessfulMountVolume   1m                 kubelet, ss-dev-kub07    MountVolume.SetUp успя за обем "sphinx-config"
  Normal  SuccessfulMountVolume   1m                 kubelet, ss-dev-kub07    MountVolume.SetUp успя за обем "default-token-fzcsf"
  Normal  SuccessfulMountVolume   49s (x2 over 51s)  kubelet, ss-dev-kub07    MountVolume.SetUp успя за обем "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normal  Pulled                  43s                kubelet, ss-dev-kub07    Контейнерният образ "registry.example.com/infrastructure/sphinx-exporter/sphinx-indexer:v1" вече е наличен на машината
  Normal  Created                 43s                kubelet, ss-dev-kub07    Създаден контейнер
  Normal  Started                 43s                kubelet, ss-dev-kub07    Стартиран контейнер
  Normal  Pulled                  43s                kubelet, ss-dev-kub07    Контейнерният образ "registry.example.com/infrastructure/sphinx/sphinx:v1" вече е наличен на машината
  Normal  Created                 42s                kubelet, ss-dev-kub07    Създаден контейнер
  Normal  Started                 42s                kubelet, ss-dev-kub07    Стартиран контейнер

След като проучихме, направихме предположението, че kubelet просто не успява да изпрати на API сървъра цялата информация за състоянието на pod’овете, liveness/readiness пробите.

И след като разгледахме help, намерихме следните параметри:

--kube-api-qps - QPS, което да се използва при комуникация с kubernetes apiserver (по подразбиране 5)
--kube-api-burst  - Burst за използване при комуникация с kubernetes apiserver (по подразбиране 10) 
--event-qps - Ако > 0, ограничава създаването на събития в секунда до тази стойност. Ако 0, неограничено. (по подразбиране 5)
--event-burst - Максимален размер на нарушенията на записите за събития, временно позволява записите на събития да нарастват до тази стойност, без да надвишават event-qps. Използва се само ако --event-qps > 0 (по подразбиране 10) 
--registry-qps - Ако > 0, ограничава QPS на теглене от регистъра до тази стойност.
--registry-burst - Максимален размер на преувеличените тегления, временно позволява да се теглят до тази стойност, без да надвишават registry-qps. Използва се само ако --registry-qps > 0 (по подразбиране 10)

Както виждате, стойностите по подразбиране са доста малки, и в 90% от случаите покриват всички нужди… Въпреки това, в нашия случай това се оказа недостатъчно. Затова поставихме следните стойности:

--event-qps=30 --event-burst=40 --kube-api-burst=40 --kube-api-qps=30 --registry-qps=30 --registry-burst=40

… и рестартирахме kubelet’ите, след което на графиките на достъпа до API сървъра видяхме следната картина:

… и да, всичко започна да лети!

P.S.

За помощта при събирането на бъгове и подготовката на статията изразявам голяма благодарност на многобройните инженери в нашата компания, а особено на колегата от нашия екип по изследвания и развитие Андрей Климентьев (zuzzas).

P.P.S.

Прочетете също в нашия блог:

• «Плъгин kubectl-debug за отстраняване на грешки в pod-ове на Kubernetes».
• Цикъл Kubernetes съвети и трикове:
  • «Превод на ресурсите, работещи в клъстера, под управлението на Helm 2»;
  • «Отделяне на възли и натоварвания на уеб приложението»;
  • «Достъп до dev площадки»;
  • «Ускоряване на стартирането на големи бази данни».

Източник: habr.com