6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

Za léta používání Kubernetes ve výrobě jsme nashromáždili mnoho zajímavých příběhů o tom, jak chyby v různých systémových komponentách vedly k nepříjemným a/nebo nepochopitelným důsledkům ovlivňujícím provoz kontejnerů a podů. V tomto článku jsme provedli výběr těch nejběžnějších nebo nejzajímavějších. I když se vám nikdy nepoštěstí takové situace potkat, čtení o takových krátkých detektivkách – zvláště „z první ruky“ – je vždy zajímavé, ne?...

Příběh 1. Supercronic a Docker zavěšení

Na jednom z clusterů jsme pravidelně dostávali zamrzlý Docker, který narušoval normální fungování clusteru. Současně bylo v protokolech Docker pozorováno 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

…

Co nás na této chybě nejvíce zajímá, je zpráva: pthread_create failed: No space left on device. Rychlé studium dokumentace vysvětlil, že Docker nemůže rozvětvit proces, a proto pravidelně zamrzá.

Při monitorování tomu, co se děje, odpovídá následující obrázek:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

Podobná situace je pozorována na jiných uzlech:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

Ve 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] <defunct>
root     17398  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root     16852  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root      9473  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root      4664  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root     30571  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root     24113  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root     16475  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root      7176  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>
root      1090  0.0  0.0      0     0 ?        Z    Feb06   0:00      |       _ [curl] <defunct>

Ukázalo se, že toto chování je důsledkem práce s pod superkronický (utilita Go, kterou používáme ke spouštění úloh cron 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] <defunct>
|       _ [curl] <defunct>
|       _ [curl] <defunct>
|       _ [curl] <defunct>
…

Problém je tento: když je úloha spuštěna v superkronice, proces ji vytvořil nelze správně ukončit, měnící se na zombie.

Poznámka: Přesněji řečeno, procesy jsou vytvářeny úlohami cron, ale supercronic není init systém a nemůže „přijmout“ procesy, které vytvořily jeho děti. Když jsou vyvolány signály SIGHUP nebo SIGTERM, nejsou předány podřízeným procesům, což má za následek, že podřízené procesy se neukončí a zůstanou ve stavu zombie. Více se o tom všem dočtete například v takový článek.

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

  1. Jako dočasné řešení - zvyšte počet PID v systému v jednom okamžiku:
           /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 spouštějte úkoly v supercronic ne přímo, ale pomocí stejného tini, který je schopen správně ukončit procesy a neplodit zombie.

Příběh 2. „Zombies“ při mazání cgroup

Kubelet začal spotřebovávat hodně CPU:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

To se nikomu nebude líbit, tak jsme se vyzbrojili perf a začal problém řešit. Výsledky vyšetřování byly následující:

  • Kubelet tráví více než třetinu svého CPU vytahováním paměťových dat ze všech cgroups:

    6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

  • V mailing listu jaderných vývojářů můžete najít diskuzi o problému. Stručně řečeno, pointa spočívá v tomto: různé soubory tmpfs a další podobné věci nejsou ze systému zcela odstraněny při mazání cgroup, tzv memcg živá mrtvola. Dříve nebo později budou vymazány z mezipaměti stránek, ale na serveru je spousta paměti a jádro nevidí důvod ztrácet čas jejich mazáním. Proto se stále hromadí. Proč se to vůbec děje? Toto je server s úlohami cron, který neustále vytváří nová pracovní místa a s nimi i nové moduly. Vznikají tak nové cgroups pro kontejnery v nich, které jsou brzy smazány.
  • Proč cAdvisor v kubelet ztrácí tolik času? To je snadno vidět při nejjednodušším provedení time cat /sys/fs/cgroup/memory/memory.stat. Pokud na zdravém stroji operace trvá 0,01 sekundy, pak na problematickém cron02 to trvá 1,2 sekundy. Jde o to, že cAdvisor, který čte data ze sysfs velmi pomalu, se snaží vzít v úvahu paměť používanou v zombie cgroups.
  • Abychom násilně odstranili zombie, pokusili jsme se vymazat mezipaměti, jak je doporučeno v LKML: sync; echo 3 > /proc/sys/vm/drop_caches, - ale jádro se ukázalo být složitější a auto havarovalo.

Co dělat? Problém se řeší (spáchat, a popis viz uvolnit zprávu) aktualizace linuxového jádra na verzi 4.16.

Historie 3. Systemd a jeho připojení

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

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

Ukázalo se, že existuje problém v systemd používaném v Ubuntu 16.04 a vyskytuje se při správě připojení, která jsou vytvořena pro připojení subPath z ConfigMaps nebo tajných informací. Poté, co modul dokončí svou práci služba systemd a její připojení služby zůstávají v systému. Postupem času se jich nahromadí obrovské množství. Na toto téma jsou dokonce problémy:

  1. #5916;
  2. kubernetes #57345.

...poslední z nich odkazuje na PR v systemd: #7811 (problém v systemd - #7798).

Problém již v Ubuntu 18.04 neexistuje, ale pokud chcete nadále používat Ubuntu 16.04, může se vám hodit naše řešení na toto téma.

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á následující 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 běží každých 5 minut pomocí výše 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. Konkurenceschopnost při plánování modulů

Bylo zjištěno, že: pokud máme pod uzel umístěný na uzlu a jeho obraz je čerpán velmi dlouhou dobu, pak další pod, který „zasáhne“ stejný uzel, jednoduše nezačne stahovat obraz nového modulu. Místo toho čeká, dokud se nevytáhne obrázek předchozího modulu. Výsledkem je, že pod, který byl již naplánován a jehož obrázek bylo možné stáhnout za pouhou minutu, skončí ve stavu containerCreating.

Události budou vypadat nějak takto:

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

Ukazuje se, že jeden obrázek z pomalého registru může zablokovat nasazení na uzel.

Bohužel z této situace není mnoho východů:

  1. Zkuste použít svůj registr Docker přímo v clusteru nebo přímo s clusterem (například registr GitLab, Nexus atd.);
  2. Používejte nástroje jako např Kraken.

Příběh 5. Uzly visí kvůli nedostatku paměti

Při provozu různých aplikací jsme se také setkali se situací, kdy uzel úplně přestane být přístupný: SSH nereaguje, odpadnou všichni monitorovací démoni a v logech pak není nic (nebo skoro nic) abnormálního.

Řeknu vám to na obrázcích na příkladu jednoho uzlu, kde fungoval MongoDB.

Takhle vypadá nahoře na nehody:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

A takhle - po nehody:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

Při monitorování dochází také k prudkému skoku, při kterém uzel přestává být dostupný:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

Ze snímků obrazovky je tedy zřejmé, že:

  1. RAM na stroji je téměř u konce;
  2. Dochází k prudkému skoku ve spotřebě RAM, po kterém je přístup k celému stroji náhle zakázán;
  3. Na Mongo přichází velký úkol, který nutí proces DBMS využívat více paměti a aktivně číst z disku.

Ukazuje se, že pokud Linuxu dojde volná paměť (nastaví se tlak na paměť) a nedojde k odkládání, pak na Když dorazí zabiják OOM, může dojít k vyvažování mezi vhozením stránek do mezipaměti stránek a jejich zapsáním zpět na disk. K tomu slouží kswapd, který statečně uvolní co nejvíce paměťových stránek pro následnou distribuci.

Bohužel s velkým I/O zatížením spojeným s malým množstvím volné paměti, kswapd se stává úzkým hrdlem celého systému, protože jsou k němu vázáni vše alokace (chyby stránek) stránek paměti v systému. To může pokračovat velmi dlouho, pokud procesy již nechtějí používat paměť, ale jsou fixovány na samém okraji propasti zabijáka OOM.

Přirozená otázka zní: proč OOM zabiják přichází tak pozdě? Ve své současné iteraci je OOM zabiják extrémně hloupý: proces zabije pouze tehdy, když selže pokus o alokaci paměťové stránky, tzn. pokud chyba stránky selže. To se nestane po dlouhou dobu, protože kswapd statečně uvolňuje stránky paměti a vyhazuje mezipaměť stránek (ve skutečnosti celý diskový I/O v systému) zpět na disk. Podrobněji s popisem kroků potřebných k odstranění takových problémů v jádře si můžete přečíst zde.

Toto chování by se měl zlepšit s linuxovým jádrem 4.6+.

Příběh 6. Lusky se zaseknou ve stavu Nevyřízeno

V některých shlucích, ve kterých funguje opravdu mnoho lusků, jsme si začali všímat, že většina z nich „visí“ velmi dlouho ve stavu Pending, ačkoli samotné kontejnery Docker již na uzlech běží a lze s nimi pracovat ručně.

Navíc v describe není nic špatného:

  Type    Reason                  Age                From                     Message
  ----    ------                  ----               ----                     -------
  Normal  Scheduled               1m                 default-scheduler        Successfully assigned sphinx-0 to ss-dev-kub07
  Normal  SuccessfulAttachVolume  1m                 attachdetach-controller  AttachVolume.Attach succeeded for volume "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normal  SuccessfulMountVolume   1m                 kubelet, ss-dev-kub07    MountVolume.SetUp succeeded for volume "sphinx-config"
  Normal  SuccessfulMountVolume   1m                 kubelet, ss-dev-kub07    MountVolume.SetUp succeeded for volume "default-token-fzcsf"
  Normal  SuccessfulMountVolume   49s (x2 over 51s)  kubelet, ss-dev-kub07    MountVolume.SetUp succeeded for volume "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normal  Pulled                  43s                kubelet, ss-dev-kub07    Container image "registry.example.com/infra/sphinx-exporter/sphinx-indexer:v1" already present on machine
  Normal  Created                 43s                kubelet, ss-dev-kub07    Created container
  Normal  Started                 43s                kubelet, ss-dev-kub07    Started container
  Normal  Pulled                  43s                kubelet, ss-dev-kub07    Container image "registry.example.com/infra/sphinx/sphinx:v1" already present on machine
  Normal  Created                 42s                kubelet, ss-dev-kub07    Created container
  Normal  Started                 42s                kubelet, ss-dev-kub07    Started container

Po nějakém kopání jsme předpokládali, že kubelet prostě nestihne poslat všechny informace o stavu podů a testech živosti/připravenosti na server API.

A po prostudování nápovědy jsme našli následující parametry:

--kube-api-qps - QPS to use while talking with kubernetes apiserver (default 5)
--kube-api-burst  - Burst to use while talking with kubernetes apiserver (default 10) 
--event-qps - If > 0, limit event creations per second to this value. If 0, unlimited. (default 5)
--event-burst - Maximum size of a bursty event records, temporarily allows event records to burst to this number, while still not exceeding event-qps. Only used if --event-qps > 0 (default 10) 
--registry-qps - If > 0, limit registry pull QPS to this value.
--registry-burst - Maximum size of bursty pulls, temporarily allows pulls to burst to this number, while still not exceeding registry-qps. Only used if --registry-qps > 0 (default 10)

Jak je vidět, výchozí hodnoty jsou poměrně malé, a z 90 % pokrývají všechny potřeby... To však v našem případě nestačilo. Proto nastavíme následující hodnoty:

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

... a restartovali jsme kubelety, načež jsme v grafech volání na server API viděli následující obrázek:

6 zábavných systémových chyb v provozu Kubernetes [a jejich řešení]

... a ano, všechno začalo létat!

PS

Za jejich pomoc při shromažďování chyb a přípravě tohoto článku vyjadřuji své hluboké poděkování četným inženýrům naší společnosti a zejména mému kolegovi z našeho R&D týmu Andrey Klimentyevovi (zuzzas).

PPS

Přečtěte si také na našem blogu:

Zdroj: www.habr.com

Přidat komentář