6 divertenti bug di sistema nel funzionamento di Kubernetes [e la loro soluzione]

Nel corso degli anni di utilizzo di Kubernetes in produzione, abbiamo accumulato molte storie interessanti su come i bug in vari componenti del sistema abbiano portato a conseguenze spiacevoli e/o incomprensibili che hanno influenzato il funzionamento di container e pod. In questo articolo abbiamo fatto una selezione di alcuni tra quelli più comuni o interessanti. Anche se non si ha mai la fortuna di imbattersi in situazioni del genere, leggere storie poliziesche così brevi - soprattutto "in prima persona" - è sempre interessante, non è vero?

Storia 1. Supercronic e Docker impiccati

Su uno dei cluster ricevevamo periodicamente un Docker congelato, che interferiva con il normale funzionamento del cluster. Allo stesso tempo, nei log Docker è stato osservato quanto segue:

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

…

Ciò che ci interessa di più di questo errore è il messaggio: pthread_create failed: No space left on device. Studio veloce documentazione ha spiegato che Docker non poteva creare un fork di un processo, motivo per cui si bloccava periodicamente.

Nel monitoraggio, la seguente immagine corrisponde a ciò che sta accadendo:

Una situazione simile si osserva su altri nodi:

Agli stessi nodi vediamo:

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>

Si è scoperto che questo comportamento è una conseguenza del funzionamento del pod supercronico (un'utilità Go che utilizziamo per eseguire lavori cron nei 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] <defunct>
|       _ [curl] <defunct>
|       _ [curl] <defunct>
|       _ [curl] <defunct>
…

Il problema è questo: quando un'attività viene eseguita in modalità supercronica, il processo viene generato da essa non può terminare correttamente, trasformandosi in zombie.

Nota: Per essere più precisi, i processi vengono generati dalle attività cron, ma supercronic non è un sistema init e non può "adottare" i processi generati dai suoi figli. Quando i segnali SIGHUP o SIGTERM vengono generati, non vengono trasmessi ai processi figli, con il risultato che i processi figli non terminano e rimangono nello stato zombie. Puoi leggere di più su tutto questo, ad esempio, in un articolo del genere.

Esistono un paio di modi per risolvere i problemi:

1. Come soluzione temporanea: aumentare il numero di PID nel sistema in un singolo momento:

          /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. Oppure avvia attività in supercronico non direttamente, ma utilizzando lo stesso tini, che è in grado di terminare correttamente i processi e di non generare zombie.

Storia 2. "Zombies" durante l'eliminazione di un cgroup

Kubelet ha iniziato a consumare molta CPU:

Questo non piacerà a nessuno, quindi ci siamo armati perf e cominciò ad affrontare il problema. I risultati dell’indagine sono stati i seguenti:

• Kubelet impiega più di un terzo del tempo della CPU estraendo dati di memoria da tutti i cgroup:

  

• Nella mailing list degli sviluppatori del kernel puoi trovare discussione del problema. In breve il punto si riduce a questo: vari file tmpfs e altre cose simili non vengono completamente rimossi dal sistema quando si elimina un cgroup, il cosiddetto memcg zombie. Prima o poi verranno eliminati dalla cache delle pagine, ma c'è molta memoria sul server e il kernel non vede il motivo di perdere tempo nell'eliminarli. Ecco perché continuano ad accumularsi. Perché sta succedendo questo? Questo è un server con lavori cron che crea costantemente nuovi lavori e con essi nuovi pod. Pertanto, vengono creati nuovi cgroup per i contenitori al loro interno, che vengono presto eliminati.
• Perché cAdvisor in kubelet perde così tanto tempo? Questo è facile da vedere con l'esecuzione più semplice time cat /sys/fs/cgroup/memory/memory.stat. Se su una macchina sana l'operazione richiede 0,01 secondi, su un cron02 problematico richiede 1,2 secondi. Il fatto è che cAdvisor, che legge i dati da sysfs molto lentamente, cerca di tenere conto della memoria utilizzata nei cgroup zombie.
• Per rimuovere forzatamente gli zombie, abbiamo provato a svuotare le cache come consigliato in LKML: sync; echo 3 > /proc/sys/vm/drop_caches, - ma il kernel si è rivelato più complicato e ha fatto schiantare l'auto.

Cosa fare? Il problema è stato risolto (commettere, e per una descrizione vedere messaggio di rilascio) aggiornando il kernel Linux alla versione 4.16.

Storia 3. Systemd e il suo supporto

Ancora una volta, il kubelet sta consumando troppe risorse su alcuni nodi, ma questa volta sta consumando troppa memoria:

Si è scoperto che c'è un problema nel systemd utilizzato in Ubuntu 16.04 e si verifica durante la gestione dei montaggi creati per la connessione subPath da ConfigMap o da segreti. Dopo che il pod ha completato il suo lavoro il servizio systemd e il relativo montaggio del servizio rimangono nel sistema. Nel corso del tempo, un numero enorme di essi si accumula. Ci sono anche problemi su questo argomento:

1. #5916;
2. Kubernetes #57345.

...l'ultimo dei quali si riferisce al PR in systemd: #7811 (problema in systemd - #7798).

Il problema non esiste più in Ubuntu 18.04, ma se vuoi continuare a utilizzare Ubuntu 16.04, potresti trovare utile la nostra soluzione alternativa su questo argomento.

Quindi abbiamo creato il seguente 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

... e utilizza il seguente script:

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

... e funziona ogni 5 minuti utilizzando il supercronico menzionato in precedenza. Il suo Dockerfile assomiglia a questo:

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

Storia 4. Competitività nella pianificazione dei pod

Si è notato che: se abbiamo un pod posizionato su un nodo e la sua immagine viene pompata per molto tempo, allora un altro pod che “colpisce” lo stesso nodo semplicemente non inizia a estrarre l'immagine del nuovo pod. Attende invece finché non viene estratta l'immagine del pod precedente. Di conseguenza, un pod già programmato e la cui immagine avrebbe potuto essere scaricata in appena un minuto finirà nello stato di containerCreating.

Gli eventi saranno simili a questi:

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

Si scopre che una singola immagine da un registro lento può bloccare la distribuzione per nodo.

Sfortunatamente, non ci sono molte vie d'uscita dalla situazione:

1. Prova ad utilizzare il tuo Docker Registry direttamente nel cluster o direttamente con il cluster (ad esempio GitLab Registry, Nexus, ecc.);
2. Utilizzare utilità come Kraken.

Storia 5. I nodi si bloccano per mancanza di memoria

Durante il funzionamento di varie applicazioni, abbiamo anche riscontrato una situazione in cui un nodo cessa completamente di essere accessibile: SSH non risponde, tutti i demoni di monitoraggio cadono e quindi non c'è nulla (o quasi nulla) di anomalo nei log.

Te lo dirò in immagini usando l'esempio di un nodo in cui ha funzionato MongoDB.

Questo è ciò che appare in cima a incidenti:

E così - dopo incidenti:

Nel monitoraggio si verifica anche un brusco salto in cui il nodo cessa di essere disponibile:

Quindi, dagli screenshot è chiaro che:

1. La RAM della macchina è quasi esaurita;
2. Si verifica un forte aumento del consumo di RAM, dopodiché l'accesso all'intera macchina viene improvvisamente disabilitato;
3. Su Mongo arriva un compito di grandi dimensioni, che costringe il processo DBMS a utilizzare più memoria e a leggere attivamente dal disco.

Si scopre che se Linux esaurisce la memoria libera (si verifica una pressione di memoria) e non c'è scambio, allora a Quando arriva il killer OOM, potrebbe sorgere un atto di bilanciamento tra gettare le pagine nella cache delle pagine e riscriverle su disco. Questo viene fatto da kswapd, che coraggiosamente libera quante più pagine di memoria possibile per la successiva distribuzione.

Sfortunatamente, con un grande carico di I/O abbinato a una piccola quantità di memoria libera, kswapd diventa il collo di bottiglia dell'intero sistema, perché sono legati ad esso tutti allocazioni (errori di pagina) delle pagine di memoria nel sistema. Questo può durare molto a lungo se i processi non vogliono più utilizzare la memoria, ma sono fissati sull'orlo dell'abisso killer OOM.

La domanda naturale è: perché il killer dell’OOM arriva così tardi? Nella sua attuale iterazione, l'OOM killer è estremamente stupido: ucciderà il processo solo quando il tentativo di allocare una pagina di memoria fallisce, cioè se l'errore di pagina fallisce. Ciò non accade per molto tempo, perché kswapd libera coraggiosamente le pagine di memoria, scaricando la cache delle pagine (l'intero I/O del disco nel sistema, in effetti) sul disco. Più in dettaglio, con una descrizione dei passaggi necessari per eliminare tali problemi nel kernel, puoi leggere qui.

Questo comportamento dovrebbe migliorare con kernel Linux 4.6+.

Storia 6. I pod rimangono bloccati nello stato In sospeso

In alcuni cluster, in cui i pod operativi sono davvero tanti, abbiamo cominciato a notare che la maggior parte di essi “si blocca” per molto tempo nello stato Pending, sebbene i contenitori Docker stessi siano già in esecuzione sui nodi e possano essere utilizzati manualmente.

Con questo in describe non c'è niente di sbagliato:

  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

Dopo alcune ricerche, abbiamo ipotizzato che kubelet semplicemente non abbia il tempo di inviare tutte le informazioni sullo stato dei pod e sui test di attività/prontezza al server API.

E dopo aver studiato l'aiuto, abbiamo trovato i seguenti parametri:

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

Come puoi vedere i valori predefiniti sono piuttosto piccoli, e nel 90% coprono tutte le esigenze... Ma nel nostro caso questo non è bastato. Pertanto impostiamo i seguenti valori:

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

... e riavviato i kubelet, dopodiché abbiamo visto la seguente immagine nei grafici delle chiamate al server API:

...e sì, tutto ha cominciato a volare!

PS

Per il loro aiuto nella raccolta dei bug e nella preparazione di questo articolo, esprimo la mia profonda gratitudine ai numerosi ingegneri della nostra azienda, e in particolare al mio collega del nostro team di ricerca e sviluppo Andrey Klimentyev (zuzzas).

PPS

Leggi anche sul nostro blog:

• «plugin kubectl-debug per il debug nei pod Kubernetes'.
• Ciclo di suggerimenti e trucchi Kubernetes:
  • «Trasferimento delle risorse in esecuzione in un cluster alla gestione Helm 2";
  • «Informazioni sull'allocazione dei nodi e sui carichi su un'applicazione web";
  • «Accesso ai siti di sviluppo";
  • «Accelerazione del bootstrap per database di grandi dimensioni'.

Fonte: habr.com