6 interessante systeemfouten bij het gebruik van Kubernetes [en hun oplossing]

Door de jaren heen hebben we bij het gebruik van Kubernetes in productie veel interessante verhalen verzameld, waarin fouten in verschillende systeemcomponenten leidden tot vervelende en/of onbegrijpelijke gevolgen die de werking van containers en pods beïnvloedden. In dit artikel hebben we een selectie gemaakt van enkele van de meest voorkomende of interessante. Zelfs als je nooit geluk hebt om in dergelijke situaties terecht te komen, is het altijd boeiend om over zulke korte detectives te lezen - vooral 'uit de eerste hand' - nietwaar?

Verhaal 1. Supercronic en vastlopende Docker

Op een van de clusters kregen we af en toe een 'vastgelopen' Docker, wat het normale functioneren van het cluster verstoorde. In de logs van Docker zagen we het volgende:

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

…

Het belangrijkste dat ons in deze fout interesseert, is de melding: pthread_create failed: No space left on device. Een vluchtige studie de documentatie verklaarde dat Docker geen proces kan fork'en, waardoor het periodiek 'vastliep'.

In de monitoring komt er het volgende in beeld:

Een soortgelijke situatie is ook op andere knooppunten te zien:

Op deze knooppunten zien we:

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]

Het bleek dat dit gedrag een gevolg was van het werken van de pod met supercronic (een tool in Go die we gebruiken voor het uitvoeren van cron-taken in pods):

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

Het probleem is als volgt: wanneer een taak wordt uitgevoerd in supercronic, kan het proces dat door hem is gestart, niet correct worden beëindigd, waardoor het verandert in een zombie.

Opmerking: Om precies te zijn, worden de processen gestart door cron-taken, maar supercronic is geen init-systeem en kan de processen die zijn kinderen zijn niet 'adopteren'. Bij het ontvangen van SIGHUP- of SIGTERM-signalen worden deze niet doorgegeven aan de processen die zijn gestart, waardoor de kindprocessen niet worden beëindigd en in de status van zombie blijven. Meer hierover kan onder andere worden gelezen in dit artikel.

Er zijn een paar manieren om de problemen op te lossen:

1. Als tijdelijke workaround — vergroot het aantal PID's in het systeem op een bepaald moment:

          /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. Of laat de taken in supercronic niet direct starten, maar met behulp van dezelfde tini, die in staat is om processen correct te beëindigen en geen zombie's te produceren.

Verhaal 2. 'Zombies' bij het verwijderen van cgroup

Kubelet begon een grote hoeveelheid CPU te verbruiken:

Dat valt niemand aan te raden, dus bewapenden we ons perf en begonnen we het probleem te onderzoeken. De uitkomsten van het onderzoek waren als volgt:

• Kubelet besteedt meer dan een derde van de CPU-tijd aan het ophalen van gegevens over geheugen uit alle cgroup:

  

• In de mailinglijst van de kernelontwikkelaars kun je een discussie over het probleem vinden. Kortom komt het erop neer dat verschillende tmpfs-bestanden en andere vergelijkbare dingen niet volledig uit het systeem worden verwijderd bij het verwijderen van cgroup — er blijven zogenaamde memcg zombies over. vroeg of laat zullen ze uit de pagina-cache verdwijnen, maar de server heeft veel geheugen en de kernel ziet geen zin in het besteden van tijd aan hun verwijdering. Daarom blijven ze zich ophopen. Waarom gebeurt dit überhaupt? Dit is een server met cron-taken die constant nieuwe taken genereert, en daarmee — nieuwe pods. Hierdoor worden er nieuwe cgroups voor de containers aangemaakt, die snel weer worden verwijderd.
• Waarom verbruikt cAdvisor in kubelet zoveel tijd? Dit is gemakkelijk te zien door simpelweg uit te voeren time cat /sys/fs/cgroup/memory/memory.stat. Als de operatie op een gezonde machine 0,01 seconde duurt, dan duurt die op de probleemmachine cron02 — 1,2 seconde. Het probleem is dat cAdvisor, dat zeer langzaam gegevens uit sysfs leest, probeert het gebruikte geheugen in zombie cgroups te berekenen.
• Om de zombies gedwongen te verwijderen, hebben we geprobeerd de caches op te schonen, zoals aanbevolen in LKML: sync; echo 3 > /proc/sys/vm/drop_caches, — maar de kernel bleek ingewikkelder en heeft de machine vastgelopen.

Wat moeten we doen? Het probleem kan worden opgelost (commit, zie de beschrijving in de release-opmerking) door de Linux-kernel bij te werken naar versie 4.16.

Verhaal 3. Systemd en zijn mounts

Wederom verbruikt kubelet te veel middelen op sommige knooppunten, maar dit keer — al het geheugen:

Het bleek dat er een probleem is met systemd, dat in Ubuntu 16.04 wordt gebruikt, en dit ontstaat bij het beheren van mounts die zijn aangemaakt voor het koppelen van subPath uit ConfigMaps of secrets. Na het beëindigen van de pod blijft de systemd-service en zijn service-mount in het systeem. In de loop der tijd accumuleert zich een enorme hoeveelheid. Over dit onderwerp zijn er zelfs issues:

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

… waarin naar een PR in systemd wordt verwezen: #7811 (issue in systemd — #7798).

Het probleem is er niet meer in Ubuntu 18.04, maar als je Ubuntu 16.04 wilt blijven gebruiken, kan onze workaround hiervoor nuttig zijn.

Dus hebben we de volgende DaemonSet gemaakt:

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

… en daarin wordt deze script gebruikt:

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

… en het wordt elke 5 minuten uitgevoerd met behulp van eerder genoemde supercronic. Zijn Dockerfile ziet er als volgt uit:

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

Hoofdstuk 4. Concurrentie bij het plannen van pods

Het is opgemerkt dat: als we een pod op een node plaatsen en zijn image lang duurt om te downloaden, dan zal een andere pod die "op dezelfde node terechtkomt", gewoon niet beginnen met het pullen van de image van de nieuwe pod. In plaats daarvan wacht hij totdat de image van de vorige pod is gedownload. Hierdoor zal de pod die al was gepland en waarvan de image in slechts een minuut had kunnen worden gedownload, voor langere tijd in de status containerCreating.

In de evenementen zal het ongeveer als volgt zijn:

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

Het blijkt dat één enkele image uit een trage registry de deployment kan blokkeren op de node.

Helaas zijn er niet veel oplossingen voor deze situatie:

1. Probeer uw Docker Registry rechtstreeks in het cluster of direkt met het cluster te gebruiken (bijvoorbeeld GitLab Registry, Nexus, enz.);
2. Gebruik tools zoals kraken.

Verhaal 5. Vastlopen van knooppunten bij geheugen tekort

Tijdens het gebruik van verschillende applicaties kwamen we ook situaties tegen waarin een knooppunt volledig onbereikbaar werd: SSH reageert niet, alle monitoringdemonen vallen uit en in de logs staat daarna niets (of bijna niets) abnormaals.

Ik zal het aan de hand van afbeeldingen uitleggen met als voorbeeld een knooppunt waar MongoDB actief was.

Zo ziet atop eruit tot crashes:

En zo — worden toegevoegd na crashes:

In de monitoring is ook een scherpe piek te zien, waarbij het knooppunt onbereikbaar wordt:

Hieruit blijkt uit de screenshots dat:

1. Het RAM op de machine bijna op is;
2. Er is een scherpe piek in het geheugenverbruik, waarna de toegang tot de hele machine abrupt wordt afgesloten;
3. Er komt een grote taak naar Mongo die ervoor zorgt dat het DBMS-proces meer geheugen gebruikt en actief van de schijf leest.

Het blijkt dat als op Linux het vrije geheugen op is (er ontstaat memory pressure) en er geen swap is, dan tot bij de komst van de OOM killer er een evenwicht kan ontstaan tussen het laden van pagina's in de page cache en het terugschrijven naar de schijf. Dit wordt uitgevoerd door kswapd, die moedig zoveel mogelijk geheugenpagina's vrijmaakt voor toekomstige distributie.

Helaas, bij een hoge I/O belasting gecombineerd met een klein aantal vrije geheugen, wordt kswapd de bottleneck van het hele systeem, omdat het zorgt voor all de toewijzingen (page faults) van geheugenpagina's in het systeem. Dit kan heel lang doorgaan als processen niet meer geheugen willen gebruiken en vastlopen op de rand van de OOM-killer-afgrond.

De vraag rijst: waarom komt de OOM killer zo laat? In zijn huidige iteratie is de OOM killer extreem dom: hij zal een proces pas beëindigen wanneer de poging om een geheugenpagina toe te wijzen mislukt, d.w.z. als de page fault met een fout eindigt. Dit gebeurt genoeg tijd niet, omdat kswapd moedig geheugenpagina's vrijmaakt door de page cache (al het schijf I/O in het systeem, in wezen) terug naar de schijf te schrijven. Voor een gedetailleerdere uitleg, met beschrijving van de stappen die nodig zijn om dergelijke problemen in de kernel op te lossen, kan men lezen hier.

Dit gedrag zou moeten verbeteren met kernel Linux 4.6+.

Geschiedenis 6. Pods blijven hangen in de status Pending

In sommige clusters waar echt veel pods draaien, hebben we opgemerkt dat het merendeel ervan heel lang in de status Pending, terwijl de Docker-containers al op de knooppunten draaien en we er handmatig mee kunnen werken.

In beschrijven is niets verkeerd:

  Type    Reden                  Leeftijd                Van                     Bericht
  ----    ------                  ----               ----                     -------
  Normaal  Gepland               1m                 default-scheduler        Succesvol toegewezen aan sphinx-0 op ss-dev-kub07
  Normaal  SuccesvolVolumeBevestigen  1m                 attachdetach-controller  AttachVolume.Attach is succesvol voor volume "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normaal  SuccesvolVolumeMonteren   1m                 kubelet, ss-dev-kub07    MountVolume.SetUp is succesvol voor volume "sphinx-config"
  Normaal  SuccesvolVolumeMonteren   1m                 kubelet, ss-dev-kub07    MountVolume.SetUp is succesvol voor volume "default-token-fzcsf"
  Normaal  SuccesvolVolumeMonteren   49s (x2 over 51s)  kubelet, ss-dev-kub07    MountVolume.SetUp is succesvol voor volume "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normaal  Getrokken                  43s                kubelet, ss-dev-kub07    Containerafbeelding "registry.example.com/infrastructure/sphinx-exporter/sphinx-indexer:v1" is al aanwezig op de machine
  Normaal  Aangemaakt                 43s                kubelet, ss-dev-kub07    Container is aangemaakt
  Normaal  Gestart                 43s                kubelet, ss-dev-kub07    Container is gestart
  Normaal  Getrokken                  43s                kubelet, ss-dev-kub07    Containerafbeelding "registry.example.com/infrastructure/sphinx/sphinx:v1" is al aanwezig op de machine
  Normaal  Aangemaakt                 42s                kubelet, ss-dev-kub07    Container is aangemaakt
  Normaal  Gestart                 42s                kubelet, ss-dev-kub07    Container is gestart

Na wat onderzoek deden we de aanname dat kubelet gewoon niet in staat is om de API-server alle informatie over de status van de pods, liveness/readiness-probes, tijdig te sturen.

En na het bestuderen van de help, vonden we de volgende parameters:

--kube-api-qps - QPS om te gebruiken bij het communiceren met de Kubernetes API-server (standaard 5)
--kube-api-burst  - Burst om te gebruiken bij het communiceren met de Kubernetes API-server (standaard 10) 
--event-qps - Als > 0, beperk het aantal evenementen per seconde tot deze waarde. Als 0, onbeperkt. (standaard 5)
--event-burst - Maximale grootte van een bursty evenementrecords, stelt tijdelijk evenementenrecords in staat om tot dit aantal te stijgen, terwijl ze nog steeds niet meer dan event-qps overschrijden. Alleen gebruikt als --event-qps > 0 (standaard 10) 
--registry-qps - Als > 0, beperk registratie pull QPS tot deze waarde.
--registry-burst - Maximale grootte van bursty pulls, stelt tijdelijk pulls in staat om tot dit aantal te stijgen, terwijl ze nog steeds niet meer dan registry-qps overschrijden. Alleen gebruikt als --registry-qps > 0 (standaard 10)

Zoals je kunt zien, standaardwaarden zijn vrij klein, en in 90% van de gevallen dekken ze alle behoeften... Maar in ons geval was dat niet genoeg. Daarom stelden we de volgende waarden in:

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

… en herstartten we de kubelets, waarna we op de grafieken van de API-server het volgende zagen:

… en ja, alles begon te vliegen!

P.S.

Voor de hulp bij het verzamelen van bugs en het voorbereiden van het artikel wil ik mijn grote dank uitspreken aan de vele ingenieurs van ons bedrijf, met name aan mijn collega uit ons R&D-team, Andrey Klimentyev (zuzzas).

P.P.S.

Lees ook op onze blog:

• «De kubectl-debug plugin voor debuggen in Kubernetes pods».
• Kubernetes tips & tricks cyclus:
  • «Migratie van werkende bronnen in een cluster naar beheer door Helm 2»;
  • «Over het toewijzen van knooppunten en lasten van webapplicaties»;
  • «Toegang tot dev-omgevingen»;
  • «Versnellen van het bootstrapproces van grote databases».

Bron: habr.com