6 цікавих системних багів при експлуатації Kubernetes [та їх вирішення]
За роки експлуатації Kubernetes у production у нас накопичилося чимало цікавих історій, як баги у різних системних компонентах призводили до неприємних та/або незрозумілих наслідків, що впливають на роботу контейнерів та pod'ів. У цій статті ми зробили добірку деяких найчастіших або найцікавіших з них. Навіть якщо вам ніколи не пощастить зіткнутися з такими ситуаціями, читати про подібні короткі детективи — тим більше «з перших рук» — завжди цікаво, хіба не так?
Історія 1. Supercronic та зависаючий Docker
На одному з кластерів ми періодично отримували «завислий» Docker, що заважало нормальному функціонуванню кластера. При цьому у логах Docker спостерігалося наступне
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
…
У цій помилці найбільше нас цікавить повідомлення: pthread_create failed: No space left on device. Побіжне вивчення документації пояснило, що Docker не може форкнути процес, через що періодично і зависав.
У моніторингу того, що відбувається, відповідає така картина:
Проблема в наступному: коли завдання запускається в supercronic, процес, породжений ним, не може коректно завершитися, перетворюючись на зомбі.
Примітка: Якщо говорити точніше, то процеси породжуються cron-завданнями, проте supercronic не є init-системою і не може «удочерити» процеси, які породили його діти У разі виникнення сигналів SIGHUP або SIGTERM вони не передаються породженим процесам, внаслідок чого дочірні процеси не завершуються, залишаючись у статусі зомбі. Докладніше про все це можна прочитати, наприклад, в такій статті.
Є кілька способів вирішення проблем:
Як тимчасовий workaround - збільшити кількість PID'ів у системі в єдиний момент часу:
/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
Або ж зробити запуск завдань у supercronic не безпосередньо, а за допомогою того ж TiNiякий здатний коректно завершувати процеси і не породжувати зомбі.
Історія 2. "Зомбі" при видаленні cgroup
Kubelet почав споживати велику кількість CPU:
Таке нікому не сподобається, тому ми озброїлися пер і почали розбиратися із проблемою. Підсумки розслідування виявилися такими:
Kubelet витрачає більше третини процесорного часу на витягування даних про пам'ять з усіх cgroup:
У розсилці розробників ядра можна знайти обговорення проблеми. Якщо коротко, то суть зводиться до того, що різні tmpfs-файли та інші схожі речі не повністю видаляються із системи при видаленні cgroup - залишаються так звані memcg зомбі. Рано чи пізно вони все ж таки видаляться з page cache, проте пам'яті на сервері багато і сенсу витрачати час на їх видалення ядро не бачить. Тому вони продовжують накопичуватися. Чому це взагалі відбувається? Це сервер із cron-завданнями, який постійно створює нові job'и, а з ними — нові pod'и. Таким чином, для контейнерів у них створюються нові cgroup, які незабаром видаляються.
Чому cAdvisor в kubelet витрачає стільки часу? Це легко побачити найпростішим виконанням time cat /sys/fs/cgroup/memory/memory.stat. Якщо на здоровій машині операція займає 0,01 секунд, то на проблемній cron02 - 1,2 секунд. Вся справа в тому, що cAdvisor, що дуже повільно читає дані з sysfs, намагається врахувати використану пам'ять і в zombie cgroups.
Щоб насильно видалити зомбі, ми спробували зачистити кеші, як рекомендували в LKML: sync; echo 3 > /proc/sys/vm/drop_caches, - Але ядро виявилося складніше і повісило машину.
Що ж робити? Проблема виправляється (коміт, а опис див. повідомленні про дозвіл) оновлення ядра Linux до версії 4.16.
Історія 3. Systemd та її mount
Знов kubelet споживає надто багато ресурсів на деяких вузлах, але цього разу вже пам'яті:
Виявилося, що є проблема в systemd, який використовується в Ubuntu 16.04, і виникає вона при керуванні mount'ами, які створюються для підключення subPath з ConfigMap'ів або secret'ів. Після завершення роботи під'а сервіс systemd та його службовий mount залишаються в системі. Згодом їх накопичується величезна кількість. На цю тему навіть є такі:
#!/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
… та він запускається кожні 5 хвилин за допомогою згаданого раніше supercronic. Його Dockerfile виглядає так:
Було помічено, що: якщо у нас на вузол розміщується pod і його образ викачується дуже довго, то інший pod, який потрапив на цей же вузол, просто не починає pull'ити образ нового pod'а. Натомість він чекає, поки з'pull'ється образ попереднього pod'а. В результаті, pod, який вже був запланований і образ якого міг би скачатися лише за хвилину, опиниться на тривалий час у статусі containerCreating.
У event'ах буде приблизно таке:
Normal Pulling 8m kubelet, ip-10-241-44-128.ap-northeast-1.compute.internal pulling image "registry.example.com/infra/openvpn/openvpn:master"
Виходить, що один-єдиний образ із повільного реєстру може заблокувати деплой на вузол.
На жаль, виходів із ситуації не так багато:
Намагайтеся використовувати свій Docker Registry прямо в кластері або безпосередньо з кластером (наприклад, GitLab Registry, Nexus тощо);
За час експлуатації різних програм ми також отримували ситуацію, коли вузол повністю перестає бути доступним: не відповідає SSH, всі демони моніторингу відвалюються, а в логах потім нічого (або майже нічого) аномального немає.
Розповім у картинках з прикладу одного вузла, де функціонувала MongoDB.
Ось так atop виглядає до аварії:
А ось так - після аварії:
У моніторингу також спостерігається різкий стрибок, при якому вузол перестає бути доступним:
Таким чином, зі скріншотів видно, що:
Оперативна пам'ять на машині близька до кінця;
Спостерігається різкий стрибок споживання оперативної пам'яті, після чого різко відключається доступ до всієї машини;
На Mongo прилітає велике завдання, яке змушує процес СУБД використовувати більше пам'яті та активно читати з диска.
Виявляється, якщо в Linux закінчується вільна пам'ять (настає memory pressure) і swap'а ні, то до приходу OOM killer'а може наступити еквілібріум між закиданням сторінок у page cache та writeback'ом їх назад на диск. Займається цим kswapd, який відважно звільняє якнайбільше сторінок пам'яті для подальшого розподілу.
На жаль, при великому навантаженні на введення/виведення разом з малою кількістю вільної пам'яті, kswapd стає пляшковим шийкою усієї системи, тому що на нього зав'язуються всі виділення сторінок пам'яті в системі. Це може тривати дуже довго, якщо процеси не захочуть більше використовувати пам'ять, а зафіксуються на краю OOM-killer-безодні.
Закономірне питання: а чому OOM killer приходить так пізно? У своїй ітерації OOM killer вкрай дурний: він приб'є процес лише тоді, коли провалиться спроба виділити сторінку пам'яті, тобто. якщо page fault пройде помилково. Цього досить довго не відбувається, тому що kswapd відважно звільняє сторінки пам'яті, скидаючи page cache (весь дисковий I/O у системі, по суті) назад на диск. Докладніше, з описом кроків, необхідних усунення подібних проблем у ядрі, можна почитати тут.
У деяких кластерах, у яких функціонує по-справжньому багато pod'ів, ми почали помічати, що більшість їх дуже довго «висить» у стані PendingХоча при цьому самі Docker-контейнери вже запущені на вузлах і з ними можна працювати вручну.
При цьому в describe нічого немає поганого:
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
Покопавшись, ми зробили припущення, що kubelet просто не встигає відправити API-серверу всю інформацію про стан pod'ів, liveness/readiness-пробах.
А вивчивши help, знайшли такі параметри:
--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)
Як видно, значення за замовчуванням - досить маленькі, і в 90% вони покривають усі потреби ... Однак у нашому випадку цього виявилося замало. Тому ми виставили такі значення:
… і перезапустили kubelet'и, після чого на графіках звернення до API-сервера побачили таку картину:
… і так, все почало літати!
PS
За допомогу у зборі багів та підготовці статті висловлюю велику подяку численним інженерам нашої компанії, а особливо – колезі з нашої R&D-команди Андрію Климентьєву (zuzzas).