• TAGES
  • Блог
  • Почему кластер Kubernetes может работать медленно

Почему кластер Kubernetes может работать медленно

Рассказываем о проблеме, которая возникла в процессе эксплуатации кластера Kubernetes.

Проблеме когда, при запасе ресурсов программы работали так, словно процессор используется на 100% или есть нехватка оперативной памяти. А также о поиске источника проблемы, пути ее решения, выдвинутых гипотезах и проведенных экспериментах.

Что случилось

В какой-то момент мы заметили, что система стала странно себя вести, хотя нагрузка на процессор и оперативную память оставалась неизменной и не уходила в потолок.

Нагрузка на ноду

Kubelet, базовая программа на нодах kubernetes, стала вести себя странно: процессор и память имели не 100% нагрузку, диск практически простаивал, никакого чтения и записи не было, но при создании подов kubelet медленно их поднимал, и это длилось в одном случае две минуты, а в другом пять.

Разница в разворачивании подов:

Events        
Type        Reason        Age     From                 Message
---         ---           ---     ---                  ---
Normal      Scheduled     5S      default-scheduler    Successfully assigned some-ns/some-pod-688653457-snqkn to k8s-node-4
Normal      Pulling       5s      kubelet              Pulling image "registry.site.ru/project/image master"
Normal      Pulled        5s      kubelet              Successfully pulled image "registry.site.ru/project/image:master" in 155.9ms
Normal      Created       342s    kubelet              Created container worker    
Normal      Started       4s      kubelet              Started container worker

Events        
Type        Reason        Age     From                 Message
---         ---           ---     ---                  ---
Normal      Scheduled     5s      default-scheduler    Successfully assigned some-ns/some-pod-688653457-snqkn to k8s-node-4
Normal      Pulling       5s      kubelet              Pulling image "registry.site.ru/project/image:master"
Normal      Pulled        5s      kubelet              Successfully pulled image "registry.site.ru/project/image master" in 155.9ms
Normal      Created       5s      kubelet              Created container worker
Normal      Started       4S      kubelet              Started container worker

На изображении выше продемонстрировано, как было (вверху) и как должно быть (внизу). Также стоит отметить, что при передеплое старые поды находились в бесконечном терминейтинге, то есть не могли завершиться.

Как выявили

  • Анализ всего

Изучая логи системы, kubelet и всего, что можно, мы поняли следующее: хотя CPU и MEM загружены не на 100%, но Load Average показывает уже значения за пределами приемлемого. Если посмотреть вывод команды top, то видно, что Load Average равен 10, при максимально положенных 8 (поскольку 8 соответствует количеству ядер CPU. Соответственно, при восьмиядерном CPU, 100% Load Average равен 8).

Вывод команды top:

top - 12:07:56 up 8 day 1:46, 1 user, load average: 10,89,12,33, 11,42
Tasks:    808    total,    1 running, 675 sleeping, 0 stopped, 0 zombie
%Cpu(s): 7,1 us, 2,8 sy, 0,0 ni, 67,4 id, 31,1 wa, 0,0 hi, 0,0 si,
МиБ Mem : 15960,3 total,    1651,7 free,    5803,9 used,    8447,7 buff/cache
МиБ Swap:0,0 total,    0,0 free,    0,0 used.    10163,3 avail Mem

Не менее странным делом стал wa со значением 31%, а wa, как говорится в мануале, это процент времени (циклов, секунд), в течение которого процессор простаивал, ожидая завершения операции ввода-вывода. Если смотреть на статистику по нагрузке на систему, но уже с Load Average, заметим, что у нас высокий Load Average, однако причина не ясна.

График нагрузки на систему с Load Average

Если посмотрим на этот же график, но уже с отображением того, что использует процессор, то увидим следующее.

Подробный график по нагрузке
  • Первые догадки

Тут уже видно, что большую часть времени процессор занят ожиданием ввода/вывода какой-то операции. Значит некий процесс или даже процессы влияют на iowait. При первом взгляде на процессы невозможно увидеть, что же с ними не так, но вот если их отфильтровать по состоянию, то уже будет видно несколько процессов, находящихся в состоянии D.

ps -aux --forest

root 10844 0.0 0.0 111700 8692? SI Jul14 1:26/usr/bin/containerd-shim-runc-v1-namespace k8s.io-id
0411fcb51221ad40f9cfa79369ed9002ff2a3974bd37461c705a3d8ffeba4830 -address /run/containerd/containerd.sock 

root      10844   0.0   0.0   111700    8692    ?   Sl    Jul14   1:26    /usr/bin/containerd-shim-runc-vl
70        10865   0.0   0.1   193128   20896    ?   Ss    Jul14   0:07    \_ postgres: 
70        11116   0.0   0.0   193252    5304    ?   Ss    Jul14   0:00    \_ postgres: checkpointer
70        11117   0.0   0.0   193224    4060    ?   Ss    Jul14   0:23    \_ postgres: background writer
70        11118   0.0   0.0   193192    7536    ?   Ss    Jul14   0:01    \_ postgres: walwriter
70        11119   0.0   0.0   193848   15768    ?   Ss    Jul14   0:18    \_ postgres: autovacuum launcher
70        11120   0.0   0.0    47648    3268    ?   Ss    Jul14   0:14    \_ postgres: stat collector
70      1663298   0.0   0.9   259752  160188    ?   Ss    Jul15   0:46    \_ postgres: archive 192.168.55.166(44910) SELECT
70      1701237   0.0   0.9   208108  155492    ?   Ss    Jul15   0:41    \_ postgres: archive 192.168.55.169(39990) UPDATE
70      1794331   0.0   1.0   258064  168340    ?   Ss    Jul15   0:05    \_ postgres: parallel worker for PID 1705
70      1794332   0.0   1.0   258064  168448    ?   Ss    Jul15   0:05    \_ postgres: parallel worker for PID 1705
70      1805219   0.0   0.0        0       0    ?   Ss    Jul15   0:00    \_ [postgres] 
70      1036859   0.0   0.0   193388    3480    ?   Ss    07:36   0:00    \_ postgres: logical replication launcher

Состояние D означает, что процесс находится в режиме сна и ожидает дискового ввода/вывода. Иначе говоря, у нас запущен под, в котором есть повисший процесс. Предположим, что-то случилось с диском. Однако система не висит, и остальные процессы работают нормально. Тогда что не так? Кто знает, что где сломалось…

Если посмотреть, что говорит kubelet, то увидим следующее:

Логи kebelet:

k8s-node-4 kubelets[763]:
pod "cbb-a0" found, but error fail to check mount point "/var/lib/kubelet/pods/cbb-a0/vol/k8s.io~nfs/pvc-5b": stat 
/var/lib/kubelet/pods/cbb-a0/vol/k8s.io~nfs/pvc-5b:
  operation not permitted occured during checking mounted volumes from disk

По сути, он говорит, что есть какой-то под, а также ошибка, которая не дает проверить точку монтирования.

  • Суммирование информации

У нас есть под, у которого что-то смонтировано, и kubelet, который ругается на точку монтирования. Еще в этом поде выполняются процессы, которые висят в состоянии D, тем самым повышая iowait, из-за которого возрос Load Average.

Если вспомнить, что за процессы там выполнялись, то поймем, что это был postgres. Скорее всего, во время работы он что-то писал на смонтированную папку, и произошел сбой. А если посмотреть describe контейнера или пода, то там как раз увидим NFS storage, в который смонтирована папка с базой postgres.

    Mounts:
      /var/lib/postgresql/data/ from storage (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-phkbs (ro)
Conditions:
  Type    Status
  Initialized    True
  Ready    True
  ContainersReady True
  PodScheduled    True
Volumes:
  storage:
    Type:    PersistentVolumeClaim    (a reference to a PersistentVolumeClaim in the same namespace)
    ClaimName:    storage-postgres-0

   Mounts:
     /var/lib/postgresql/data/ from storage (rw)
  Volumes:    <none>
Volume Claims:
  Name:    storage

Как решили

  • Идея

В какой-то момент возникла мысль: «А давайте убьем под - и дело с концом. Посмотрим, правда ли в нем проблема была». Что мы и сделали. После этого под завис в состоянии терменейтинг и не завершался.

  • Эксперименты

Завершаем под принудительно и… ничего. Load Average опустился немного и снова возрос. А что с процессами?

Процессы, что остались:

root      10844   0.0   0.0   111700    8692    ?   Sl    Jul14   1:28    /usr/bin/containerd
70        10865   0.0   0.0        0       0    ?   Ss    Jul14   0:07    \_ [postgres]
70      1701237   0.0   0.0        0       0    ?   Ds    Jul15   0:41    \_ [postgres]
70      1805219   0.0   0.0        0       0    ?   Ss    Jul14   0:00    \_ [postgres]

Те, что были в состоянии D, так и остались. Тут возникла новая идея: «Тогда давайте завершим процесс. Проверим, что у нас этот процесс есть внутри контейнера». Здесь уже нам открылись два пути: напрямую убить процесс на хостовой машине или завершить внутри контейнера.

Завершение работы контейнера:

ctrl -n k8s.io task Is | grep 10865

tages@k8s-node-4:-$ sudo ctr -n k8s.io task Is | grep 16865
0411fcb51221ad40f9cfa79369ed9002ff2a3974bd37461c705a3d8ffeba4830    10865 RUNNING

Ctrl -n k8s.io task kill -s SIGKILL 0411fcb51221ad40f9cfa79369ed9002ff2a3974bd37461c705a3d8ffeba4830
kill -9 10865

Применили команды.

Ничего не произошло:

tages<ak8s-node-4:ps -efl | awk ‘{if ($2 == “D”) print $0}’
1 D     root      1182329     2   0   80    0 -   0 -     08:36 ?     00:00:00  [10.0.30.100-man]
1 D     70        1701237 10865   0   80    0 -   0 -     Jull5 ?     00:00:41  [postgres]
1 0     70        1805219 10865   0   80    0 -   0 -     Jull5 ?     00:00:00  [postgres]
tages@k8s-node-4:~$ sudo ctr -n k8s.io task Is | grep 10865
0411fcb51221ad40f9cfa79369ed9002ff2a3974bd37461c705a3d8ffeba4830    10865    RUNNING
tages@k8s-node-4: $ sudo ctr -n k8s.io task kill -s SIGKILL 0411fcb51221ad40f9cfa79369ed9002ff2a3974bd37461c705a3d8ffeba4830
tages@k8s-node-4: $ ps -efl | awk '{if ($2 == ”0") print $0}'
1 D     root      1183177     2   0   80    0 -   0 -     08:36 ?     00:00:00  [10.0.30.100-man]
1 D     70        1701237 10865   0   80    0 -   0 -     Jull5 ?     00:00:41  [postgres]
1 D     70        1805219 10865   0   80    0 -   0 -     Jull5 ?     00:00:00  [postgres]
tages@k8s-node-4:~$ sudo ctr -n k8s.io task Is | grep 10865
O411fcb51221ad40f9cfa79369ed9002ff2a3974bd37461c705a3d8ffeba4830    10865    RUNNING

root      10844   0.0   0.0   111700    8692  ?   SI    Jull4   1:28  /usr/bin/containerd
70        10865   0.0   0.0        0       0  ?   Ss    Jull4   0:07  \_ [postgres]
70      1701237   0.0   0.0        0       0  ?   Ds    Jull5   0:41  \_ [postgres]
70      1805219   0.0   0.0        0       0  ?   Ds    Jull5   0:00  \_ [postgres]

Все осталось, как и было. И тут возник вопрос: «Что не так, почему они не завершаются?».

  • Эврика

На самом деле всё оказалось очень просто. По порядку: запускается под, монтируется база по NFS, запускается Postgres и начинает работать с базой. В какой-то момент работы базы, например, UPGRADE DELETE WRITE, наш сервер с NFS-HDD не успевает обработать поток данных (не забываем, что у NFS тоже есть свой iowait, а у диска iops происходит задержка в записи/чтении, и postgres повисает на выполнении команды). К слову, конкретно эта база оказалась слишком большой, и была запущена на NFS-HDD. В результате получили повисший процесс в состоянии D. Следом kubelet, так как он все контролирует и запускает, начинает много времени уделять на под с зависшим процессом, вследствие чего происходит медленный старт и остановка подов.

А убить процесс мы уже не можем, так как он работает в режиме непрерывности, ядро не позволит его убить, пока не завершится ввод/вывод данных на/с диска.n

Остался только один вариант решения текущей проблемы - полностью перезагрузить ноду, ведь процесс нам уже не завершить.

Итоги

Мы практически избавились от подобных проблем и нивелировали при возникновении в будущем, а также сделали выводы:

  1. При использовании NFS, в рамках Kubernetes, следует обязательно использовать NFSv3 с опцией soft. Так как NFSv4 является stateful-протоколом и может использовать только hard опцию, а значит может подвиснуть в случае потери соединения и заморозить I/O, что у нас и происходило. В то же время, NFSv3 является stateless-протоколом и может использовать опцию soft, так что в случае потери соединения он просто выдаст ошибку, после чего сразу перезапустится.
  2. Не использовать медленные диски на задачах, которые слишком часто обращаются к диску. В нашем случае мы перенесли ресурсоемкие проекты на NFS-SSD.
  3. Не использовать медленную сеть на больших объемах данных для NFS и контролировать поток данных.
  4. Корректно и с запасом выделять ресурсы на серверах для всех проектов, потому что один проект, который потребляет слишком много ресурсов, может навредить работе других. К примеру, даже если у вас быстрый диск, но выделено мало процессорного времени, то к процессору будет копиться очередь на обработку запросов к диску.
  5. Необходимо реализовать мониторинг метрик и оповещений. Чтобы узнавать о надвигающейся нагрузке заранее мы выделили часть метрик и создали оповещения на Load Average и iowait со значениями близкими к пороговым.

Бонус: рекомендуем для прочтения

Для углубления в тему Load Average советуем ознакомиться со следующими материалами:

Автор: Максим Абдулхаликов (DevOps-инженер TAGES)

Назад

Похожие публикации