6 bug di sistema interessanti durante l'utilizzo di Kubernetes [e come risolverli]

Negli anni di utilizzo di Kubernetes in produzione, abbiamo accumulato molte storie interessanti su come bug in vari componenti di sistema abbiano portato a conseguenze spiacevoli e/o incomprensibili, influenzando il funzionamento dei container e dei pod. In questo articolo abbiamo raccolto alcune delle più frequenti o interessanti. Anche se non ti capiterà mai di incontrare tali situazioni, leggere su simili brevi misteri — soprattutto “di prima mano” — è sempre affascinante, non credi?

Storia 1. Supercronic e Docker bloccato

In uno dei cluster, ci trovavamo periodicamente con un Docker "bloccato", il che ostacolava il normale funzionamento del cluster. Nei log di Docker, appariva 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

…

In quest'errore, ci interessa maggiormente il messaggio: pthread_create failed: No space left on device. Un'analisi rapida documentazione ha spiegato che Docker non può forkare il processo, il che ha causato periodiche "congelamenti".

Nel monitoraggio della situazione si presenta tale quadro:

Situazioni simili si osservano anche su altri nodi:

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

Si è scoperto che questo comportamento è una conseguenza del funzionamento del pod con supercronic (uno strumento in Go che utilizziamo per eseguire compiti 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] 
|       _ [curl] 
|       _ [curl] 
|       _ [curl] 
|       _ [curl] 
…

Il problema è il seguente: quando un'attività viene avviata in supercronic, il processo generato da essa, non riesce a terminare correttamente, trasformandosi in zombi.

Nota: Per essere più precisi, i processi vengono generati da attività cron, tuttavia supercronic non è un sistema init e non può 'adottare' i processi generati dai suoi figli. Quando si verificano segnali SIGHUP o SIGTERM, questi non vengono trasmessi ai processi generati, con il risultato che i processi figli non terminano, rimanendo nello stato di zombi. Puoi leggere di più su tutto questo, ad esempio in in questo articolo.

Ci sono alcuni modi per risolvere i problemi:

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

          /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 eseguire i compiti in supercronic non direttamente, ma usando lo stesso tini, che è in grado di terminare correttamente i processi e non generare zombie.

Storia 2. 'Zombie' durante la rimozione di cgroup

Kubelet ha iniziato a consumare una grande quantità di CPU:

Questo non piace a nessuno, quindi ci siamo armati perf e abbiamo iniziato a indagare sul problema. I risultati dell'indagine sono stati i seguenti:

• Kubelet spende più di un terzo del tempo della CPU per estrarre i dati sulla memoria da tutti i cgroup:

  

• Nella mailing list degli sviluppatori del kernel puoi trovare discussione sul problema. In breve, il problema è che diversi file tmpfs e altre cose simili non vengono completamente rimossi dal sistema alla rimozione di cgroup – rimangono quelli che vengono definiti memcg zombie. Prima o poi verranno rimossi dalla cache della pagina, ma il server ha molta memoria e il kernel non vede ragioni per perdere tempo a rimuoverli. Quindi continuano ad accumularsi. Perché succede tutto questo? Questo è un server con cron job che crea costantemente nuovi lavori e, con essi, nuovi pod. Così, per i contenitori vengono creati nuovi cgroup, che presto vengono eliminati.
• Perché cAdvisor in kubelet impiega tanto tempo? È facile vederlo eseguendo il comando più semplice time cat /sys/fs/cgroup/memory/memory.stat. Se su una macchina sana l'operazione richiede 0,01 secondi, su cron02, che ha problemi, richiede 1,2 secondi. Il motivo è che cAdvisor, leggendo i dati da sysfs molto lentamente, cerca di tenere conto della memoria utilizzata anche nei cgroup zombie.
• Per forzare l'eliminazione dei zombie, abbiamo provato a pulire le cache, come consigliato in LKML: sync; echo 3 > /proc/sys/vm/drop_caches, — ma il kernel si è rivelato più complicato e ha bloccato la macchina.

Cosa fare? Il problema può essere risolto (commit, e per una descrizione, vedere il messaggio di rilascio) aggiornando il kernel Linux alla versione 4.16.

Storia 3. Systemd e il suo mount

Ancora una volta kubelet consuma troppe risorse su alcuni nodi, ma questa volta — già memoria:

Si è scoperto che c'è un problema in systemd, utilizzato in Ubuntu 16.04, che si verifica durante la gestione dei mount creati per il collegamento subPath da ConfigMap o secret. Dopo la chiusura del pod il servizio systemd e il suo mount di servizio rimangono nel sistema. Col tempo si accumulano in numero considerevole. A riguardo ci sono anche delle issue:

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

… in quest'ultima si fa riferimento a un PR in systemd: #7811 (issue in systemd — #7798).

Il problema non esiste più in Ubuntu 18.04, ma se desiderate continuare a utilizzare Ubuntu 16.04, potrebbe esservi utile il nostro workaround al riguardo.

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 uno script del genere:

#!/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 viene eseguito ogni 5 minuti grazie a supercronic, già menzionato in precedenza. Il suo Dockerfile appare così:

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. Concorrenza nella pianificazione dei pod

È stato osservato che: se abbiamo un pod in un nodo e la sua immagine viene scaricata molto lentamente, un altro pod che "finisce" nello stesso nodo semplicemente non inizia a scaricare l'immagine del nuovo pod. Invece, aspetta che l'immagine del pod precedente venga scaricata. Di conseguenza, il pod che era già stato programmato e la cui immagine avrebbe potuto essere scaricata in un minuto si troverà a lungo nello stato containerCreating.

Negli eventi ci sarà circa il seguente:

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

Ciò significa che un'unica immagine da un registro lento può bloccare il deployment sul nodo.

Purtroppo, le soluzioni a questo problema non sono molte:

1. Cercate di utilizzare il vostro Docker Registry direttamente nel cluster o direttamente con il cluster (ad esempio, GitLab Registry, Nexus, ecc.);
2. Utilizzate strumenti come kraken.

Storia 5. Blocco dei nodi per mancanza di memoria

Durante l'utilizzo di diverse applicazioni, abbiamo anche riscontrato situazioni in cui un nodo smette di essere completamente accessibile: non risponde a SSH, tutti i demoni di monitoraggio si disconnettono e nei log non ci sono (o quasi) anomalie.

Lo mostrerò con immagini utilizzando un nodo dove funzionava MongoDB.

Ecco come appare atop fino a incidenti:

Ecco come appare — dopo incidenti:

Nel monitoraggio si osserva anche un brusco aumento, durante il quale il nodo smette di essere accessibile:

Pertanto, dalle schermate si può vedere che:

1. La memoria RAM sulla macchina sta per esaurirsi;
2. Si osserva un brusco aumento del consumo di memoria RAM, dopo il quale l'accesso all'intera macchina viene interrotto;
3. Arriva un grande compito su Mongo, che costringe il processo del DBMS a utilizzare più memoria e a leggere attivamente dal disco.

Si scopre che se in Linux termina la memoria libera (si verifica una pressione della memoria) e non c'è swap, fino a Con il sopraggiungere dell'OOM killer può instaurarsi un equilibrio tra il caricamento delle pagine nella cache e il loro writeback sul disco. A occuparsene è kswapd, che si prodiga per liberare quante più pagine di memoria possibile per la successiva allocazione.

Purtroppo, sotto un alto carico di input/output combinato con una scarsa disponibilità di memoria, kswapd diventa il collo di bottiglia dell'intero sistema, poiché a lui si collegano tutti le allocazioni (page faults) delle pagine di memoria nel sistema. Questo può durare a lungo, se i processi non decidono di utilizzare più memoria, rimanendo bloccati proprio al bordo dell'abisso OOM killer.

Sorge spontanea la domanda: perché l'OOM killer interviene così tardi? Nella sua attuale iterazione, l'OOM killer è estremamente stupido: terminerà un processo solo quando fallirà il tentativo di allocare una pagina di memoria, ovvero se il page fault si verifica con un errore. Questo non accade per molto tempo, poiché kswapd si prodiga per liberare le pagine di memoria, scaricando la cache delle pagine (tutto l'I/O del disco nel sistema, in sostanza) sul disco. Per ulteriori dettagli, con una descrizione dei passaggi necessari per risolvere problemi simili nel kernel, si può leggere qui.

Questo comportamento deve migliorare con il kernel Linux 4.6+.

Storia 6. I pod rimangono in stato di Pending

In alcuni cluster, dove operano davvero molti pod, abbiamo iniziato a notare che gran parte di essi rimane 'bloccata' in stato Pending, anche se i container Docker sono già avviati sui nodi e si può lavorare manualmente con essi.

Tuttavia, in describe non c'è niente di male:

  Tipo    Motivo                  Età                Da                     Messaggio
  ----    ------                  ----               ----                     -------
  Normale Pianificato              1m                 default-scheduler        Assegnato con successo sphinx-0 a ss-dev-kub07
  Normale AttachVolumeSuccess       1m                 attachdetach-controller  AttachVolume.Attach riuscito per volume "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normale SuccessfulMountVolume     1m                 kubelet, ss-dev-kub07    MountVolume.SetUp riuscito per volume "sphinx-config"
  Normale SuccessfulMountVolume     1m                 kubelet, ss-dev-kub07    MountVolume.SetUp riuscito per volume "default-token-fzcsf"
  Normale SuccessfulMountVolume     49s (x2 in 51s)   kubelet, ss-dev-kub07    MountVolume.SetUp riuscito per volume "pvc-6aaad34f-ad10-11e8-a44c-52540035a73b"
  Normale Estratto                43s                kubelet, ss-dev-kub07    L'immagine del container "registry.example.com/intra/sphinx-exporter/sphinx-indexer:v1" è già presente sulla macchina
  Normale Creato                 43s                kubelet, ss-dev-kub07    Container creato
  Normale Avviato                 43s                kubelet, ss-dev-kub07    Container avviato
  Normale Estratto                43s                kubelet, ss-dev-kub07    L'immagine del container "registry.example.com/intra/sphinx/sphinx:v1" è già presente sulla macchina
  Normale Creato                 42s                kubelet, ss-dev-kub07    Container creato
  Normale Avviato                 42s                kubelet, ss-dev-kub07    Container avviato

Esaminando le informazioni, abbiamo ipotizzato che kubelet non riesca semplicemente a inviare all'API-server tutte le informazioni sullo stato dei pod, sui controlli di liveness/readiness.

Dopo aver esaminato l'aiuto, abbiamo trovato i seguenti parametri:

--kube-api-qps - QPS da utilizzare durante la comunicazione con il kubernetes apiserver (default 5)
--kube-api-burst - Picco da utilizzare durante la comunicazione con il kubernetes apiserver (default 10) 
--event-qps - Se > 0, limita le creazioni di eventi al secondo a questo valore. Se 0, illimitato. (default 5)
--event-burst - Dimensione massima di un evento burst, consente temporaneamente di far crescere gli eventi fino a questo numero, senza superare event-qps. Utilizzato solo se --event-qps > 0 (default 10) 
--registry-qps - Se > 0, limita il QPS di pull del registro a questo valore.
--registry-burst - Dimensione massima dei pull burst, consente temporaneamente di far crescere i pull fino a questo numero, senza superare registry-qps. Utilizzato solo se --registry-qps > 0 (default 10)

Come si può vedere, i valori predefiniti sono piuttosto piccoli, e nel 90 % dei casi soddisfano tutte le esigenze… Tuttavia, nel nostro caso si sono rivelati insufficienti. Pertanto, abbiamo impostato i seguenti valori:

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

… e abbiamo riavviato i kubelet, dopo di che nei grafici delle richieste al API-server abbiamo visto la seguente situazione:

… e sì, tutto ha iniziato a volare!

P.S.

Desidero ringraziare sinceramente i numerosi ingegneri della nostra azienda per il supporto nella raccolta dei bug e nella preparazione dell’articolo, e in particolare il collega del nostro team R&D, Andrey Klimentyev (zuzzas).

P.P.S.

Leggete anche nel nostro blog:

• «Plugin kubectl-debug per il debugging nei pod di Kubernetes».
• Ciclo Kubernetes tips & tricks:
  • «Conversione delle risorse operative nel cluster sotto Helm 2»;
  • «Sull'allocazione dei nodi e sui carichi delle applicazioni web»;
  • «Accesso agli ambienti di sviluppo»;
  • «Acceleriamo il bootstrap di grandi basi di dati».

Fonte: habr.com