6 interesujących błędów systemowych podczas korzystania z Kubernetes [i ich rozwiązanie]

W ciągu lat korzystania z Kubernetes w produkcji zebraliśmy wiele intrygujących historii, jak błędy w różnych komponentach systemowych prowadziły do nieprzyjemnych i/lub niejasnych konsekwencji wpływających na działanie kontenerów i podów. W tym artykule zebraliśmy niektóre z najczęstszych lub interesujących z nich. Nawet jeśli nigdy nie spotkasz się z takimi sytuacjami, czytanie o podobnych krótkich detektywach — tym bardziej „z pierwszej ręki” — zawsze jest fascynujące, prawda?

Historia 1. Supercronic i zawieszony Docker

Na jednym z klastrów okresowo mieliśmy „zawieszony” Docker, co utrudniało normalne funkcjonowanie klastra. W logach Dockera zaobserwowano następujące

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

…

W tym błędzie najbardziej interesuje nas komunikat: pthread_create failed: No space left on device. Szybka analiza dokumentacji wyjaśniła, że Docker nie może forkować procesu, przez co okresowo „zawieszał się”.

Na monitoringu sytuacja wyglądała następująco:

Podobna sytuacja występuje również na innych węzłach:

Na tych samych węzłach widzimy:

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]

Okazało się, że takie zachowanie jest wynikiem działania poda z supercronic (narzędzie napisane w Go, które używamy do uruchamiania zadań cron w podach):

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

Problem jest następujący: gdy zadanie jest uruchamiane w supercronic, proces przez niego stworzony, nie może poprawnie zakończyć się, stając się zombi.

Uwaga: Dokładniej mówiąc, procesy są generowane przez zadania cron, jednak supercronic nie jest systemem init i nie może „adoptować” procesów, które są jego dziećmi. W przypadku wystąpienia sygnałów SIGHUP lub SIGTERM, nie są one przekazywane do stworzonych procesów, przez co procesy potomne nie kończą się, pozostając w stanie zombie. Więcej na ten temat można przeczytać w takim artykule.

Istnieje kilka sposobów rozwiązania problemów:

1. Jako tymczasowe rozwiązanie — zwiększenie liczby PID-ów w systemie w danym momencie:

          /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. Można też uruchamiać zadania w supercronic nie bezpośrednio, ale za pomocą tego samego tini, który potrafi poprawnie zakończyć procesy i nie stwarza zombi.

Historia 2. „Zombi” podczas usuwania cgroup

Kubelet zaczął zużywać dużą ilość CPU:

Takie coś nikomu się nie spodoba, więc uzbroiliśmy się w perf i zaczęliśmy badać problem. Wnioski śledztwa okazały się następujące:

• Kubelet spędza więcej niż jedną trzecią czasu procesora na pobieraniu danych o pamięci z cgroup:

  

• Na liście deweloperów jądra można znaleźć dyskusję na temat problemu. W skrócie, chodzi o to, że różne pliki tmpfs oraz inne podobne rzeczy nie są całkowicie usuwane z systemu po usunięciu cgroup — pozostają tzw. memcg zombi. W końcu zostaną usunięte z pamięci podręcznej strony, jednak na serwerze jest dużo pamięci, więc jądro nie widzi sensu w poświęcaniu czasu na ich usuwanie. Dlatego nadal się gromadzą. Dlaczego to w ogóle się dzieje? To serwer z zadaniami cron, który stale tworzy nowe zadania, a z nimi – nowe pod'y. W ten sposób dla kontenerów tworzone są nowe cgroup, które wkrótce zostaną usunięte.
• Dlaczego cAdvisor w kubelet zużywa tyle czasu? Można to łatwo zobaczyć, wykonując najprostsze polecenie: time cat /sys/fs/cgroup/memory/memory.stat. Jeśli na zdrowej maszynie operacja zajmuje 0,01 sekundy, to na problematycznym cron02 – 1,2 sekundy. Chodzi o to, że cAdvisor bardzo wolno odczytuje dane z sysfs, próbując uwzględnić zużytą pamięć i w zombie cgroups.
• Aby na siłę usunąć zombie, próbowaliśmy wyczyścić pamięci podręczne, jak zalecano w LKML: sync; echo 3 > /proc/sys/vm/drop_caches, — ale jądro okazało się bardziej skomplikowane i zawiesiło maszynę.

Co robić? Problem jest naprawiany (commitu, a opis znajdziesz w notatce o wydaniu) poprzez aktualizację jądra Linux do wersji 4.16.

Historia 3. Systemd i jego montaż

Znowu kubelet zużywa zbyt wiele zasobów na niektórych węzłach, ale tym razem — już pamięci:

Okazało się, że jest problem w systemd używanym w Ubuntu 16.04, który występuje podczas zarządzania montażami stworzonymi dla podłączenia subPath z ConfigMap'ów lub secret'ów. Po zakończeniu pracy pod'a usługa systemd i jej montaż pozostają w systemie. Z czasem gromadzi się ich ogromna ilość. Na ten temat są nawet problemy:

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

… w ostatnim z nich odniesiono się do PR w systemd: #7811 (problem w systemd — #7798).

Problem już nie występuje w Ubuntu 18.04, ale jeśli nadal chcesz korzystać z Ubuntu 16.04, możesz potrzebować naszego obejścia w tej kwestii.

Tak więc, zrobiliśmy następujący 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

… i używany jest następujący skrypt:

#!/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 uruchamiany jest co 5 minut przy użyciu wspomnianego wcześniej supercronic. Jego Dockerfile wygląda następująco:

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

Historia 4. Współbieżność przy planowaniu pod'ów

Zauważono, że: jeśli na węzeł umieszczany jest pod i jego obraz jest pobierany bardzo długo, to inny pod, który trafił na ten sam węzeł, po prostu nie zaczyna pobierać obrazu nowego pod'a. Zamiast tego czeka, aż pobieranie obrazu poprzedniego pod'a się zakończy. W rezultacie, pod, który już został zaplanowany i którego obraz mógłby zostać pobrany w ciągu zaledwie minuty, przez długi czas pozostaje w statusie containerCreating.

W zdarzeniach będzie mniej więcej coś takiego:

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

Wynika z tego, że jeden jedyny obraz z wolnego rejestru może zablokować wdrożenie na węzeł.

Niestety, możliwości rozwiązania tej sytuacji nie jest zbyt wiele:

1. Staraj się używać swojego rejestru Docker bezpośrednio w klastrze lub bezpośrednio z klastrem (na przykład GitLab Registry, Nexus itp.);
2. Skorzystaj z takich narzędzi jak kraken.

Historia 5. Zawieszanie węzłów przy braku pamięci

Podczas eksploatacji różnych aplikacji napotykaliśmy również sytuacje, gdy węzeł przestaje być całkowicie dostępny: nie odpowiada na SSH, wszystkie demony monitorujące przestają działać, a w logach nie ma (lub prawie nie ma) nic anormalnego.

Przedstawię to na przykładzie jednego węzła, na którym działała MongoDB.

Tak wygląda atop do awarie:

A tak — po awarie:

W monitoringu również widać nagły skok, po którym węzeł przestaje być dostępny:

W ten sposób z zrzutów ekranu widać, że:

1. Pamięć RAM na maszynie jest bliska końca;
2. Obserwuje się nagły skok zużycia pamięci RAM, po którym nagle traci się dostęp do całej maszyny;
3. Na Mongo przychodzi duże zadanie, które zmusza proces SGBD do używania większej ilości pamięci i aktywnego odczytywania z dysku.

Okazuje się, że jeśli w Linuksie kończy się wolna pamięć (następuje presión pamięci) i nie ma swapu, to do przybycie OOM killera może doprowadzić do równowagi między wrzucaniem stron do pamięci podręcznej i ich zrzutem z powrotem na dysk. Zajmuje się tym kswapd, który odważnie zwalnia jak najwięcej stron pamięci do dalszego przydziału.

Niestety, przy dużym obciążeniu wejścia/wyjścia i małej ilości wolnej pamięci, kswapd staje się wąskim gardłem całego systemu, ponieważ to na nim opierają się wszystkie przydziały (page faults) stron pamięci w systemie. Może to trwać bardzo długo, jeśli procesy nie będą chciały więcej używać pamięci i zatrzymają się na krawędzi otchłani OOM-killera.

Logiczne jest pytanie: dlaczego OOM killer przychodzi tak późno? W obecnej iteracji OOM killer jest wysoce nieefektywny: zabije proces tylko wtedy, gdy nie powiodą się próby przydzielenia strony pamięci, tzn. jeśli page fault zakończy się błędem. To na długo się nie zdarza, ponieważ kswapd odważnie zwalnia strony pamięci, zrzucając pamięć podręczną (cały I/O dysku w systemie) z powrotem na dysk. Szczegółowy opis kroków niezbędnych do rozwiązania podobnych problemów w jądrze można przeczytać tutaj.

To zachowanie powinno ulec poprawie z jądrem Linux 4.6+.

Historia 6. Pod'y pozostają w stanie Oczekiwanie

W niektórych klastrach, w których działa naprawdę dużo pod'ów, zaczęliśmy zauważać, że większość z nich bardzo długo „wisi” w stanie Pending, mimo że same kontenery Docker są już uruchomione na węzłach i można z nimi ręcznie pracować.

Jednakże w describe nie ma nic złego:

  Typ    Powód                     Wiek                Z From                      Komunikat
  ----    ------                   ----               ----                      -------
  Normal  Zaplanowane               1m                 domyślny-scheduler        Z powodzeniem przypisano sphinx-0 do ss-dev-kub07
  Normal  SkuteczneDodanieObjętości 1m                 attachdetach-controller  Złączenie objętości powiodło się dla objętości "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normal  SkuteczneZamontowanieObjętości 1m                 kubelet, ss-dev-kub07    Ustawienie montażu objętości powiodło się dla objętości "sphinx-config"
  Normal  SkuteczneZamontowanieObjętości 1m                 kubelet, ss-dev-kub07    Ustawienie montażu objętości powiodło się dla objętości "default-token-fzcsf"
  Normal  SkuteczneZamontowanieObjętości 49s (x2 w ciągu 51s)  kubelet, ss-dev-kub07    Ustawienie montażu objętości powiodło się dla objętości "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normal  Pobranie                  43s                kubelet, ss-dev-kub07    Obraz kontenera "registry.example.com/infra/sphinx-exporter/sphinx-indexer:v1" już znajduje się na maszynie
  Normal  Utworzenie                 43s                kubelet, ss-dev-kub07    Utworzono kontener
  Normal  Rozpoczęcie                43s                kubelet, ss-dev-kub07    Rozpoczęto kontener
  Normal  Pobranie                  43s                kubelet, ss-dev-kub07    Obraz kontenera "registry.example.com/infra/sphinx/sphinx:v1" już znajduje się na maszynie
  Normal  Utworzenie                 42s                kubelet, ss-dev-kub07    Utworzono kontener
  Normal  Rozpoczęcie                42s                kubelet, ss-dev-kub07    Rozpoczęto kontener

Po zbadaniu sprawy zasugerowaliśmy, że kubelet po prostu nie nadąża z wysyłaniem do API serwera wszystkich informacji o stanie pod'ów, liveness/readiness prób.

I badając pomoc, znaleźliśmy następujące parametry:

--kube-api-qps - QPS do użycia podczas rozmowy z serwerem API Kubernetes (domyślnie 5)
--kube-api-burst  - Burst do użycia podczas rozmowy z serwerem API Kubernetes (domyślnie 10) 
--event-qps - Jeśli > 0, ogranicz liczbę tworzenia zdarzeń na sekundę do tej wartości. Jeśli 0, brak ograniczeń. (domyślnie 5)
--event-burst - Maksymalny rozmiar burzy rekordów zdarzeń, tymczasowo pozwala na wzrost rekordów zdarzeń do tej liczby, nie przekraczając przy tym event-qps. Używane tylko, jeśli --event-qps > 0 (domyślnie 10) 
--registry-qps - Jeśli > 0, ogranicz pull QPS rejestrów do tej wartości.
--registry-burst - Maksymalny rozmiar burzy pulli, tymczasowo pozwala na wzrost pulli do tej liczby, nie przekraczając przy tym registry-qps. Używane tylko, jeśli --registry-qps > 0 (domyślnie 10)

As we can see, domyślne wartości — dość małe, i w 90 % pokrywają wszystkie potrzeby… Jednak w naszym przypadku okazało się to niewystarczające. Dlatego ustawiliśmy takie wartości:

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

… i zrestartowaliśmy kubelet'y, po czym na wykresach dostępu do serwera API zobaczyliśmy następujący obraz:

… i tak, wszystko zaczęło działać!

P.S.

Chciałbym serdecznie podziękować wielu inżynierom naszej firmy za pomoc w zbieraniu błędów i przygotowaniu artykułu, a w szczególności mojemu koledze z zespołu R&D, Андрею Климентьеву (zuzzas).

P.P.S.

Przeczytaj także na naszym blogu:

• «Plugin kubectl-debug do debugowania w podach Kubernetes».
• Cykl wskazówek i trików Kubernetes:
  • «Tłumaczenie działających w klastrze zasobów pod zarządzanie Helm 2»;
  • «O wydzieleniu węzłów i obciążeniach na aplikację webową»;
  • «Dostęp do dev-środowisk»;
  • «Przyspieszamy bootstrap dużych baz danych».

Źródło: habr.com