6 zajímavých systémových chyb při provozu Kubernetes [a jejich řešení]

Během let používání Kubernetes v produkčním prostředí jsme nasbírali řadu zajímavých příběhů, jak chyby v různých systémových komponentách vedly k nepříjemným a/nebo nejasným následkům, které ovlivnily provoz kontejnerů a podů. V tomto článku jsme udělali výběr některých z nejčastějších nebo nejzajímavějších z nich. I když se možná nikdy nesetkáte s takovými situacemi, čtení o podobných krátkých detektivkách — zejména

Příběh 1. Supercronic a zamrzlý Docker

Na jednom z clusterů jsme občas zaznamenávali „zamrzlý“ Docker, což bránilo normálnímu fungování clusteru. V logách Dockeru se objevovaly následující

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

…

Na této chybě nás nejvíce zajímá zpráva: pthread_create failed: No space left on device. Rychlé zkoumání dokumentaci vysvětlilo, že Docker nemůže forkovat proces, což způsobilo jeho občasné „zamrznutí“.

V monitorování odpovídající situaci odpovídá následující obraz:

Podobná situace se vyskytuje i na dalších uzlech:

Na těchto stejných uzlech vidíme:

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]

Ukázalo se, že takové chování je důsledkem práce podu se supercronic (nástroj v Go, který používáme k provádění cron úloh v podech):

 _ 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] 
…

Problém je následující: když úloha běží v supercronic, proces, který je jím vytvořen, nemůže správně skončit, mění se na zombie.

Poznámka: Přesněji řečeno, procesy jsou vytvářeny cron úlohami, ale supercronic není init systém a nemůže „adoptovat“ procesy, které vytvořily jeho děti. Při vzniku signálů SIGHUP nebo SIGTERM nejsou předávány potomkům, což způsobuje, že rodičovské procesy nezkončí a zůstanou ve statusu zombie. Podrobnosti o tom lze nalézt například v takovém článku.

Existuje několik způsobů, jak řešit problémy:

1. Jako dočasné workaround — zvýšit počet PID'ů v systému v jeden okamžik:

          /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. Nebo spustit úlohy v supercronic ne přímo, ale pomocí stejného tini, který je schopen správně ukončit procesy a nezpůsobit zombie.

Příběh 2. „Zombie“ při odstraňování cgroup

Kubelet začal spotřebovávat velké množství CPU:

To se nikomu nelíbí, takže jsme se vybavili perf a začali se zabývat problémem. Závěry vyšetřování byly následující:

• Kubelet tráví více než třetinu procesorového času získáváním dat o paměti ze všech cgroup:

  

• V mailing listu vývojářů jádra lze nalézt diskuzi o problému. Ve zjednodušené podobě jde o to, že různé tmpfs soubory a další podobné věci se zcela neodstraňují ze systému při odstraňování cgroup — zůstávají takzvané memcg zombie. Dříve nebo později budou odstraněny z page cache, nicméně na serveru je dost paměti a jádro nevidí smysl v tom ztrácet čas jejich odstraňováním. Proto se stále hromadí. Proč se to vůbec děje? Jde o server s cron úlohami, který neustále vytváří nové úkoly, a s nimi — nové pod. Tím se vytvářejí nové cgroup pro kontejnery, které jsou brzy odstraněny.
• Proč cAdvisor v kubeletu spotřebovává tolik času? Je to snadné zjistit provedením time cat /sys/fs/cgroup/memory/memory.stat. Pokud na zdravém stroji operace trvá 0,01 sekundy, tak na problémovém cron02 - 1,2 sekundy. Všechno spočívá v tom, že cAdvisor, který velmi pomalu čte data ze sysfs, se snaží zohlednit použité paměti a zombie cgroups.
• Abychom násilně odstranili zombie, pokusili jsme se vyčistit cache, jak doporučovali v LKML: sync; echo 3 > /proc/sys/vm/drop_caches, — ale jádro se ukázalo jako složitější a pověsilo stroj.

Co dělat? Problém se řeší (commit, a popis naleznete v poznámce k vydání) aktualizací jádra Linux na verzi 4.16.

Historie 3. Systemd a jeho mount

Znovu kubelet spotřebovává příliš mnoho zdrojů na některých uzlech, ale tentokrát — již paměti:

Ukázalo se, že existuje problém v systemd, používaném v Ubuntu 16.04, a nastává při správě mountů, které jsou vytvářeny pro připojení subPath z ConfigMap nebo secret. Po skončení práce pod služba systemd a její servisní mount zůstávají v systému. V průběhu času jich hromadí obrovské množství. Na toto téma existují dokonce problémy:

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

… v posledním z nich odkazují na PR v systemd: #7811 (issue v systemd — #7798).

Problémy již nejsou v Ubuntu 18.04, ale pokud chcete i nadále používat Ubuntu 16.04, náš workaround může být užitečný.

Takže jsme vytvořili následující 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

… a používá se takový skript:

#!/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

… a spouští se každých 5 minut pomocí již zmíněného supercronic. Jeho Dockerfile vypadá takto:

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"]

Příběh 4. Konkurenčnost při plánování podů

Bylo pozorováno, že: pokud se na uzel umístí pod a jeho obraz se stahuje velmi dlouho, jiný pod, který se "chybně" umístil na stejný uzel, jednoduše nezačne stahovat obraz nového podu.Místo toho čeká, až se stáhne obraz předchozího podu. V důsledku toho pod, který již byl naplánován a jehož obraz by mohl být stažen během jedné minuty, zůstane po delší dobu ve stavu containerCreating.

V událostech bude přibližně následující:

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

Dostáváme se k tomu, že jediný obraz z pomalého registru může zablokovat nasazení na uzel.

Bohužel, možností, jak situaci řešit, není příliš mnoho:

1. Snažte se používat svůj Docker Registry přímo v clusteru nebo přímo s clusterem (například GitLab Registry, Nexus atd.);
2. Využijte takové nástroje jako kraken.

Historie 5. Zaseknutí uzlů při nedostatku paměti

Během provozu různých aplikací jsme se také dostali do situace, kdy uzel úplně přestal být dostupný: neodpovídal SSH, všechny monitorovací démony odpadly a v logách pak nebylo (nebo téměř nic) anomálních událostí.

Povím vám to na obrázcích na příkladu jednoho uzlu, kde fungovala MongoDB.

Takto vypadá atop do havárie:

A takto — po havárie:

V monitorování také pozorujeme prudký skok, při kterém uzel přestává být dostupný:

Z obrázků je tedy vidět, že:

1. Operační paměť na zařízení se blíží k vyčerpání;
2. Dochází k prudkému skoku spotřeby operační paměti, po kterém se přístup k celému zařízení okamžitě vypíná;
3. Na Mongo přichází velký úkol, který donutí proces DBMS používat více paměti a aktivně číst z disku.

Ukazuje se, že pokud v Linuxu skončí volná paměť (nastane memory pressure) a swap není, do příchod OOM killer může přinést rovnováhu mezi přidáváním stránek do page cache a jejich zpětným zapisováním na disk. O to se stará kswapd, který odvážně uvolňuje co nejvíce stránek paměti pro další rozdělení.

Bohužel, při vysokém zatížení vstupu/výstupu v kombinaci s malým množstvím volné paměti, se kswapd stává úzkým hrdlem celého systému, protože na něm závisí všechny alokace (page faults) stránek paměti v systému. To může trvat velmi dlouho, pokud procesy nechtějí více využívat paměť a zůstanou zafixovány na samotném okraji propasti OOM-killera.

Je na místě otázka: proč OOM killer přichází tak pozdě? V aktuální své iteraci je OOM killer extrémně hloupý: zabije proces pouze tehdy, když selže pokus o alokaci stránky paměti, tj. pokud page fault projde s chybou. To se dost dlouho neděje, protože kswapd odvážně uvolňuje stránky paměti, resetováním page cache (vlastně veškerého diskového I/O v systému) zpět na disk. Podrobněji s popisem kroků nezbytných pro odstranění takových problémů v jádře si můžete přečíst zde.

Toto chování by se mělo zlepšit s jádrem Linux 4.6+.

Historie 6. Pod'y visí ve stavu Pending

V některých klastrech, kde skutečně funguje hodně pod'ů, jsme začali pozorovat, že většina z nich velmi dlouho "visí" ve stavu Pending, přičemž samotné Docker kontejnery již běží na uzlech a lze s nimi pracovat ručně.

Přitom není popis nic špatného:

  Typ    Důvod                  Věk                Od                     Zpráva
  ----    ------                  ----               ----                     -------
  Normální  Naplánováno           1m                 default-scheduler        Úspěšně přiřazeno sphinx-0 na ss-dev-kub07
  Normální  Úspěšné připojení objemu  1m                 attachdetach-controller  Připojení objemu bylo úspěšné pro objem "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normální  Úspěšné připojení objemu   1m                 kubelet, ss-dev-kub07    Úspěšné nastavení objektu objemu pro objem "sphinx-config"
  Normální  Úspěšné připojení objemu   1m                 kubelet, ss-dev-kub07    Úspěšné nastavení objektu objemu pro objem "default-token-fzcsf"
  Normální  Úspěšné připojení objemu   49s (x2 za 51s)  kubelet, ss-dev-kub07    Úspěšné nastavení objektu objemu pro objem "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normální  Staženo                  43s                kubelet, ss-dev-kub07    Obraz kontejneru "registry.example.com/informa/sphinx-exporter/sphinx-indexer:v1" již přítomen na stroji
  Normální  Vytvořeno                 43s                kubelet, ss-dev-kub07    Vytvořen kontejner
  Normální  Spuštěno                 43s                kubelet, ss-dev-kub07    Kontejner byl spuštěn
  Normální  Staženo                  43s                kubelet, ss-dev-kub07    Obraz kontejneru "registry.example.com/informa/sphinx/sphinx:v1" již přítomen na stroji
  Normální  Vytvořeno                 42s                kubelet, ss-dev-kub07    Vytvořen kontejner
  Normální  Spuštěno                 42s                kubelet, ss-dev-kub07    Kontejner byl spuštěn

Po prozkoumání jsme učinili předpoklad, že kubelet prostě nestíhá poslat API serveru všechny informace o stavu pod'ů, liveness/readiness probech.

A po prostudování help jsme našli následující parametry:

--kube-api-qps - QPS pro komunikaci s kubernetes apiserverem (výchozí 5)
--kube-api-burst  - Burst pro komunikaci s kubernetes apiserverem (výchozí 10) 
--event-qps - Pokud > 0, omezit vytváření událostí za sekundu na tuto hodnotu. Pokud 0, neomezeno. (výchozí 5)
--event-burst - Maximální velikost burstových záznamů událostí, dočasně umožňuje událostem tolik vytvořit, zatímco stále nepřekračují event-qps. Používá se pouze pokud --event-qps > 0 (výchozí 10) 
--registry-qps - Pokud > 0, omezit QPS pro tažení registru na tuto hodnotu.
--registry-burst - Maximální velikost burstových stahování, dočasně umožňuje stahováním tolik, zatímco stále nepřekračují registry-qps. Používá se pouze pokud --registry-qps > 0 (výchozí 10)

Jak vidno, výchozí hodnoty — poměrně malé, a v 90 % pokrývají všechny potřeby… Avšak v našem případě toho bylo nedostatečně. Proto jsme nastavili takové hodnoty:

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

… a restartovali kubelet'y, po čemž jsme na grafech přístupu k API serveru viděli následující obrázek:

… a ano, všechno začalo letět!

P.S.

Děkuji mnoha inženýrům naší společnosti za pomoc při shromažďování chyb a přípravě článku, zejména kolegovi z našeho týmu R&D Andrey Klimentyevovi (zuzzas).

P.P.S.

Přečtěte si také náš blog:

• «Plugin kubectl-debug pro debugování v pod'ách Kubernetes».
• Cyklus tipů a triků Kubernetes:
  • «Převod fungujících zdrojů v clusteru pod správu Helm 2»;
  • «O vyhrazených uzlech a o zatížení webové aplikace»;
  • «Přístup k dev-platformám»;
  • «Zrychlujeme bootstrap velkých databází».

Zdroj: habr.com