Кубернетес пред неколку години на официјалниот блог на GitHub. Оттогаш, таа стана стандардна технологија за распоредување услуги. Kubernetes сега управува со значителен дел од внатрешните и јавните услуги. Како што растеа нашите кластери и барањата за изведба станаа построги, почнавме да забележуваме дека некои услуги на Kubernetes спорадично доживуваат латентност што не може да се објасни со оптоварувањето на самата апликација.
Во суштина, апликациите искусуваат навидум случајна мрежна латентност до 100 ms или повеќе, што резултира со тајмаути или повторно обиди. Се очекуваше дека услугите ќе можат да одговорат на барањата многу побрзо од 100 ms. Но, ова е невозможно ако самата врска одзема толку многу време. Посебно, забележавме многу брзи MySQL барања кои требаше да бидат потребни милисекунди, а MySQL заврши за милисекунди, но од перспектива на апликацијата што бараше, одговорот траеше 100 ms или повеќе.
Веднаш стана јасно дека проблемот настанал само при поврзување со јазол на Кубернет, дури и ако повикот дошол надвор од Кубернет. Најлесен начин да се репродуцира проблемот е во тест , кој работи од кој било внатрешен хост, ја тестира услугата Kubernetes на одредена порта и спорадично регистрира висока латентност. Во оваа статија, ќе погледнеме како успеавме да ја пронајдеме причината за овој проблем.
Елиминирање на непотребната сложеност во синџирот што води до неуспех
Со репродуцирање на истиот пример, сакавме да го стесниме фокусот на проблемот и да ги отстраниме непотребните слоеви на сложеност. Првично, имаше премногу елементи во протокот помеѓу Вегета и мешунките Кубернет. За да идентификувате подлабок проблем со мрежата, треба да исклучите некои од нив.
Клиентот (Вегета) создава TCP врска со кој било јазол во кластерот. Kubernetes работи како преклопена мрежа (на врвот на постоечката мрежа на центарот за податоци) што користи , односно ги инкапсулира IP пакетите на преклопената мрежа во IP пакетите на центарот за податоци. Кога се поврзувате со првиот јазол, се врши превод на мрежна адреса (NAT) со статус за преведување на IP адресата и пристаништето на јазолот Kubernetes на IP адресата и портата во преклопната мрежа (конкретно, подлогата со апликацијата). За дојдовните пакети, се врши обратна низа на дејства. Тоа е комплексен систем со многу состојба и многу елементи кои постојано се ажурираат и менуваат додека услугите се распоредуваат и преместуваат.
Алатка tcpdump во Вегета тестот има доцнење за време на TCP ракување (помеѓу SYN и SYN-ACK). За да ја отстраните оваа непотребна сложеност, можете да користите hping3 за едноставни „пингови“ со SYN пакети. Проверуваме дали има доцнење во пакетот за одговор, а потоа ја ресетираме врската. Можеме да ги филтрираме податоците за да вклучиме само пакети поголеми од 100 ms и да добиеме полесен начин за репродукција на проблемот отколку тестот за целосниот мрежен слој 7 во Вегета. Еве ги „пинговите“ на јазолот на Кубернетес користејќи TCP SYN/SYN-ACK на услугата „нод порта“ (30927) во интервали од 10 ms, филтрирани со најбавните одговори:
theojulienne@shell ~ $ sudo hping3 172.16.47.27 -S -p 30927 -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1485 win=29200 rtt=127.1 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1486 win=29200 rtt=117.0 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1487 win=29200 rtt=106.2 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1488 win=29200 rtt=104.1 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=5024 win=29200 rtt=109.2 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=5231 win=29200 rtt=109.2 ms
Може веднаш да го направи првото набљудување. Судејќи според секвенциските броеви и тајмингот, јасно е дека не станува збор за еднократни метеж. Доцнењето често се акумулира и на крајот се обработува.
Следно, сакаме да дознаеме кои компоненти може да бидат вклучени во појавата на застојот. Можеби ова се некои од стотиците правила на iptables во NAT? Или има проблеми со IPIP тунелирањето на мрежата? Еден начин да се тестира ова е да се тестира секој чекор од системот со негово елиминирање. Што се случува ако ја отстраните логиката на NAT и заштитен ѕид, оставајќи го само делот IPIP:
За среќа, Linux го олеснува директно пристапот до слојот за преклопување на IP ако машината е на истата мрежа:
theojulienne@kube-node-client ~ $ sudo hping3 10.125.20.64 -S -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=40 ip=10.125.20.64 ttl=64 DF id=0 sport=0 flags=RA seq=7346 win=0 rtt=127.3 ms
len=40 ip=10.125.20.64 ttl=64 DF id=0 sport=0 flags=RA seq=7347 win=0 rtt=117.3 ms
len=40 ip=10.125.20.64 ttl=64 DF id=0 sport=0 flags=RA seq=7348 win=0 rtt=107.2 ms
Судејќи според резултатите, проблемот сепак останува! Ова ги исклучува iptables и NAT. Значи проблемот е TCP? Ајде да видиме како оди обичниот пинг ICMP:
theojulienne@kube-node-client ~ $ sudo hping3 10.125.20.64 --icmp -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=28 ip=10.125.20.64 ttl=64 id=42594 icmp_seq=104 rtt=110.0 ms
len=28 ip=10.125.20.64 ttl=64 id=49448 icmp_seq=4022 rtt=141.3 ms
len=28 ip=10.125.20.64 ttl=64 id=49449 icmp_seq=4023 rtt=131.3 ms
len=28 ip=10.125.20.64 ttl=64 id=49450 icmp_seq=4024 rtt=121.2 ms
len=28 ip=10.125.20.64 ttl=64 id=49451 icmp_seq=4025 rtt=111.2 ms
len=28 ip=10.125.20.64 ttl=64 id=49452 icmp_seq=4026 rtt=101.1 ms
len=28 ip=10.125.20.64 ttl=64 id=50023 icmp_seq=4343 rtt=126.8 ms
len=28 ip=10.125.20.64 ttl=64 id=50024 icmp_seq=4344 rtt=116.8 ms
len=28 ip=10.125.20.64 ttl=64 id=50025 icmp_seq=4345 rtt=106.8 ms
len=28 ip=10.125.20.64 ttl=64 id=59727 icmp_seq=9836 rtt=106.1 ms
Резултатите покажуваат дека проблемот не исчезнал. Можеби ова е IPIP тунел? Ајде дополнително да го поедноставиме тестот:
Дали сите пакети се испраќаат помеѓу овие два домаќини?
theojulienne@kube-node-client ~ $ sudo hping3 172.16.47.27 --icmp -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=46 ip=172.16.47.27 ttl=61 id=41127 icmp_seq=12564 rtt=140.9 ms
len=46 ip=172.16.47.27 ttl=61 id=41128 icmp_seq=12565 rtt=130.9 ms
len=46 ip=172.16.47.27 ttl=61 id=41129 icmp_seq=12566 rtt=120.8 ms
len=46 ip=172.16.47.27 ttl=61 id=41130 icmp_seq=12567 rtt=110.8 ms
len=46 ip=172.16.47.27 ttl=61 id=41131 icmp_seq=12568 rtt=100.7 ms
len=46 ip=172.16.47.27 ttl=61 id=9062 icmp_seq=31443 rtt=134.2 ms
len=46 ip=172.16.47.27 ttl=61 id=9063 icmp_seq=31444 rtt=124.2 ms
len=46 ip=172.16.47.27 ttl=61 id=9064 icmp_seq=31445 rtt=114.2 ms
len=46 ip=172.16.47.27 ttl=61 id=9065 icmp_seq=31446 rtt=104.2 ms
Ја поедноставивме ситуацијата на два Kubernetes јазли кои меѓусебно испраќаат каков било пакет, дури и ICMP пинг. Тие сè уште гледаат доцнење ако целниот домаќин е „лош“ (некои полоши од другите).
Сега последното прашање: зошто доцнењето се случува само на серверите на kube-node? И дали се случува кога kube-node е испраќачот или примачот? За среќа, ова е исто така доста лесно да се открие со испраќање пакет од домаќин надвор од Кубернетес, но со истиот „познат лош“ примач. Како што можете да видите, проблемот не исчезна:
theojulienne@shell ~ $ sudo hping3 172.16.47.27 -p 9876 -S -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=312 win=0 rtt=108.5 ms
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=5903 win=0 rtt=119.4 ms
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=6227 win=0 rtt=139.9 ms
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=7929 win=0 rtt=131.2 ms
Потоа ќе ги извршиме истите барања од претходниот изворен kube-јазол до надворешниот хост (што го исклучува изворниот хост бидејќи пингот вклучува и RX и TX компонента):
theojulienne@kube-node-client ~ $ sudo hping3 172.16.33.44 -p 9876 -S -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
^C
--- 172.16.33.44 hping statistic ---
22352 packets transmitted, 22350 packets received, 1% packet loss
round-trip min/avg/max = 0.2/7.6/1010.6 ms
Со испитување на заробени пакети за латентност, добивме некои дополнителни информации. Поточно, дека испраќачот (долу) го гледа овој истек на време, но примачот (горе) не - видете ја колоната Делта (во секунди):
Дополнително, ако ја погледнете разликата во редоследот на TCP и ICMP пакетите (по секвентни броеви) на страната на примачот, ICMP пакетите секогаш пристигнуваат во истата низа по која се испратени, но со различен тајминг. Во исто време, TCP пакетите понекогаш се преплетуваат, а некои од нив се заглавуваат. Конкретно, ако ги испитате портите на SYN пакетите, тие се во ред од страната на испраќачот, но не и од страната на примачот.
Има суптилна разлика во тоа како современите сервери (како оние во нашиот центар за податоци) обработуваат пакети што содржат TCP или ICMP. Кога ќе пристигне пакетот, мрежниот адаптер го „хеши по конекција“, односно се обидува да ги прекине врските во редици и да ја испрати секоја редица до посебно процесорско јадро. За TCP, овој хаш ги вклучува и изворната и одредишната IP адреса и портата. Со други зборови, секоја врска е хеширана (потенцијално) различно. За ICMP, само IP адресите се хашираат, бидејќи нема порти.
Друга нова опсервација: во овој период гледаме одложувања на ICMP на сите комуникации помеѓу два домаќини, но TCP не. Ова ни кажува дека причината најверојатно е поврзана со хаширањето на редиците RX: застојот е речиси сигурно во обработката на RX пакетите, а не во испраќањето одговори.
Ова го елиминира испраќањето пакети од листата на можни причини. Сега знаеме дека проблемот со обработката на пакетите е на страната за примање на некои сервери на kube-јазол.
Разбирање на обработката на пакети во кернелот Линукс
За да разбереме зошто проблемот се јавува кај ресиверот на некои сервери на kube-јазол, ајде да погледнеме како кернелот на Linux ги обработува пакетите.
Враќајќи се на наједноставната традиционална имплементација, мрежната картичка го прима пакетот и испраќа кернелот на Линукс дека има пакет што треба да се обработи. Јадрото запира друга работа, го префрла контекстот на управувачот со прекини, го обработува пакетот и потоа се враќа на тековните задачи.
Ова префрлување на контекстот е бавно: латентноста можеби не беше забележлива на мрежните картички со брзина од 10 Mbps во 90-тите, но на модерните 10G картички со максимална пропусност од 15 милиони пакети во секунда, секое јадро на мал сервер со осум јадра може да биде прекинато со милиони пати во секунда.
За да не се справува постојано со прекини, пред многу години додаде Linux : Мрежен API што го користат сите модерни драјвери за да ги подобрат перформансите при големи брзини. При мали брзини, кернелот сè уште прима прекини од мрежната картичка на стариот начин. Откако ќе пристигнат доволно пакети кои го надминуваат прагот, кернелот ги оневозможува прекините и наместо тоа започнува да го истражува мрежниот адаптер и да ги собира пакетите на парчиња. Обработката се врши во softirq, односно во по системски повици и хардверски прекини, кога кернелот (за разлика од корисничкиот простор) веќе работи.
Ова е многу побрзо, но предизвикува поинаков проблем. Ако има премногу пакети, тогаш целото време се троши на обработка на пакети од мрежната картичка, а процесите на корисничкиот простор немаат време всушност да ги испразнат овие редици (читање од TCP врски итн.). На крајот редиците се пополнуваат и почнуваме да испуштаме пакети. Во обид да се најде рамнотежа, кернелот поставува буџет за максималниот број на пакети обработени во контекстот softirq. Откако ќе се надмине овој буџет, се буди посебна нишка ksoftirqd (ќе видите еден од нив во ps по јадро) што се справува со овие softirq надвор од нормалната патека за syscall/interrupt. Оваа нишка е закажана со користење на стандардниот распоредувач на процеси, кој се обидува правично да ги распредели ресурсите.
Откако проучивте како кернелот ги обработува пакетите, можете да видите дека постои одредена веројатност за застој. Ако softirq повиците се примаат поретко, пакетите ќе треба да чекаат некое време за да се обработат во редот RX на мрежната картичка. Ова може да се должи на некоја задача што го блокира јадрото на процесорот или нешто друго го спречува јадрото да работи softirq.
Стеснување на обработката до јадрото или методот
Одложувањата на Softirq засега се само претпоставка. Но, има смисла, и знаеме дека гледаме нешто многу слично. Така, следниот чекор е да се потврди оваа теорија. И ако се потврди, тогаш пронајдете ја причината за одложувањата.
Да се вратиме на нашите бавни пакети:
len=46 ip=172.16.53.32 ttl=61 id=29573 icmp_seq=1953 rtt=99.3 ms
len=46 ip=172.16.53.32 ttl=61 id=29574 icmp_seq=1954 rtt=89.3 ms
len=46 ip=172.16.53.32 ttl=61 id=29575 icmp_seq=1955 rtt=79.2 ms
len=46 ip=172.16.53.32 ttl=61 id=29576 icmp_seq=1956 rtt=69.1 ms
len=46 ip=172.16.53.32 ttl=61 id=29577 icmp_seq=1957 rtt=59.1 ms
len=46 ip=172.16.53.32 ttl=61 id=29790 icmp_seq=2070 rtt=75.7 ms
len=46 ip=172.16.53.32 ttl=61 id=29791 icmp_seq=2071 rtt=65.6 ms
len=46 ip=172.16.53.32 ttl=61 id=29792 icmp_seq=2072 rtt=55.5 ms
Како што беше дискутирано претходно, овие ICMP пакети се хашираат во една редица RX NIC и се обработуваат од едно јадро на процесорот. Ако сакаме да разбереме како функционира Linux, корисно е да знаеме каде (на кое јадро на процесорот) и како (softirq, ksoftirqd) се обработуваат овие пакети за да се следи процесот.
Сега е време да користите алатки кои ви дозволуваат да го следите кернелот на Linux во реално време. Тука користевме . Овој сет на алатки ви овозможува да пишувате мали C програми кои закачуваат произволни функции во кернелот и ги тампонираат настаните во програма на Python во кориснички простор што може да ги обработи и да ви го врати резултатот. Закачувањето на произволни функции во кернелот е незгодна работа, но алатката е дизајнирана за максимална безбедност и е дизајнирана да го следи токму видот на производните проблеми што не се репродуцираат лесно во тест или развојна средина.
Планот овде е едноставен: знаеме дека кернелот ги обработува овие ICMP пингови, па ќе ставиме кука на функцијата на јадрото , кој прифаќа дојдовен пакет со барање за ехо ICMP и иницира испраќање на ICMP ехо одговор. Можеме да идентификуваме пакет со зголемување на бројот icmp_seq, што покажува hping3 повисоко.
Код изгледа комплицирано, но не е толку страшно како што изгледа. Функција icmp_echo пренесува struct sk_buff *skb: Ова е пакет со „барање за ехо“. Можеме да го следиме, да ја извлечеме низата echo.sequence (што се споредува со icmp_seq со hping3 выше), и испратете го до корисничкиот простор. Исто така е погодно да се сними името/ид на тековниот процес. Подолу се резултатите што ги гледаме директно додека кернелот обработува пакети:
TGID PID ИМЕ НА ПРОЦЕСОТ ICMP_SEQ 0 0 разменувач/11 770 0 разменувач/0 11 771 разменувач/0 0 11 разменувач/772 0 0 разменувач/11 773 0 прометеј 0 11 774 разменувач/20041 20086 775 разменувач/0 0 11 разменувач/776 0 0 spokes-report-s 11
Овде треба да се забележи дека во контекст softirq процесите што направиле системски повици ќе се појават како „процеси“ кога всушност кернелот е тој што безбедно ги обработува пакетите во контекст на кернелот.
Со оваа алатка можеме да поврземе специфични процеси со специфични пакети кои покажуваат доцнење на hping3. Ајде да го направиме едноставно grep на ова зафаќање за одредени вредности icmp_seq. Пакетите што одговараат на горенаведените вредности icmp_seq беа означени заедно со нивниот RTT што го забележавме погоре (во загради се очекуваните RTT вредности за пакетите што ги филтриравме поради RTT вредности помали од 50ms):
TGID PID ИМЕ НА ПРОЦЕСОТ ICMP_SEQ ** RTT -- 10137 10436 cadvisor 1951 година 10137 10436 cadvisor 1952 година 76 76 ksoftirqd/11 1953 ** 99ms 76 76 ksoftirqd/11 1954 ** 89ms 76 76 ksoftirqd/11 1955 ** 79ms 76 76 ksoftirqd/11 1956 ** 69ms 76 76 ksoftirqd/11 1957 ** 59ms 76 76 ksoftirqd/11 1958 ** (49ms) 76 76 ksoftirqd/11 1959 ** (39ms) 76 76 ksoftirqd/11 1960 ** (29ms) 76 76 ksoftirqd/11 1961 ** (19ms) 76 76 ksoftirqd/11 1962 ** (9ms) -- 10137 10436 cadvisor 2068 година 10137 10436 cadvisor 2069 година 76 76 ksoftirqd/11 2070 ** 75ms 76 76 ksoftirqd/11 2071 ** 65ms 76 76 ksoftirqd/11 2072 ** 55ms 76 76 ksoftirqd/11 2073 ** (45ms) 76 76 ksoftirqd/11 2074 ** (35ms) 76 76 ksoftirqd/11 2075 ** (25ms) 76 76 ksoftirqd/11 2076 ** (15ms) 76 76 ksoftirqd/11 2077 ** (5ms)
Резултатите ни кажуваат неколку работи. Прво, сите овие пакети се обработуваат според контекстот ksoftirqd/11. Ова значи дека за овој конкретен пар машини, ICMP пакетите беа хаширани до јадрото 11 на приемниот крај. Гледаме и дека секогаш кога има џем, има пакети кои се обработуваат во контекст на системскиот повик cadvisor. Тогаш ksoftirqd ја презема задачата и ја обработува акумулираната редица: точно бројот на пакети што се акумулирале по cadvisor.
Фактот дека веднаш пред тоа секогаш функционира cadvisor, имплицира негово вклучување во проблемот. Иронично, целта - „анализирајте го користењето на ресурсите и карактеристиките на изведбата на контејнерите што работат“, наместо да го предизвикувате овој проблем со перформансите.
Како и со другите аспекти на контејнерите, сите овие се високо напредни алатки и може да се очекува дека ќе доживеат проблеми со перформансите под некои непредвидени околности.
Што прави cadvisor што го успорува редот на пакети?
Сега имаме прилично добро разбирање за тоа како се случува падот, кој процес го предизвикува и на кој процесор. Гледаме дека поради тешко блокирање, кернелот на Линукс нема време за закажување ksoftirqd. И гледаме дека пакетите се обработуваат во контекст cadvisor. Логично е да се претпостави дека cadvisor започнува бавен syscall, по што сите пакети акумулирани во тоа време се обработуваат:
Ова е теорија, но како да се тестира? Она што можеме да го направиме е да го следиме јадрото на процесорот во текот на овој процес, да ја најдеме точката каде што бројот на пакети го надминува буџетот и се нарекува ksoftirqd, а потоа да погледнеме малку поназад за да видиме што точно работи на јадрото на процесорот непосредно пред таа точка. . Тоа е како рентген на процесорот на секои неколку милисекунди. Ќе изгледа отприлика вака:
Погодно, сето ова може да се направи со постоечки алатки. На пример, проверува дадено јадро на процесорот на одредена фреквенција и може да генерира распоред на повици до системот што работи, вклучувајќи го и корисничкиот простор и кернелот на Linux. Можете да го земете овој запис и да го обработите користејќи мала вилушка од програмата од Брендан Грег, кој го зачувува редот на трагата на оџакот. Можеме да зачуваме траги од стек од една линија на секои 1 ms, а потоа да означиме и зачуваме примерок 100 милисекунди пред да се појави трагата ksoftirqd:
# record 999 times a second, or every 1ms with some offset so not to align exactly with timers
sudo perf record -C 11 -g -F 999
# take that recording and make a simpler stack trace.
sudo perf script 2>/dev/null | ./FlameGraph/stackcollapse-perf-ordered.pl | grep ksoftir -B 100
Еве ги резултатите:
(сотни следов, которые выглядят похожими)
cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_iter cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages ksoftirqd/11;ret_from_fork;kthread;kthread;smpboot_thread_fn;smpboot_thread_fn;run_ksoftirqd;__do_softirq;net_rx_action;ixgbe_poll;ixgbe_clean_rx_irq;napi_gro_receive;netif_receive_skb_internal;inet_gro_receive;bond_handle_frame;__netif_receive_skb_core;ip_rcv_finish;ip_rcv;ip_forward_finish;ip_forward;ip_finish_output;nf_iterate;ip_output;ip_finish_output2;__dev_queue_xmit;dev_hard_start_xmit;ipip_tunnel_xmit;ip_tunnel_xmit;iptunnel_xmit;ip_local_out;dst_output;__ip_local_out;nf_hook_slow;nf_iterate;nf_conntrack_in;generic_packet;ipt_do_table;set_match_v4;ip_set_test;hash_net4_kadt;ixgbe_xmit_frame_ring;swiotlb_dma_mapping_error;hash_net4_test ksoftirqd/11;ret_from_fork;kthread;kthread;smpboot_thread_fn;smpboot_thread_fn;run_ksoftirqd;__do_softirq;net_rx_action;gro_cell_poll;napi_gro_receive;netif_receive_skb_internal;inet_gro_receive;__netif_receive_skb_core;ip_rcv_finish;ip_rcv;ip_forward_finish;ip_forward;ip_finish_output;nf_iterate;ip_output;ip_finish_output2;__dev_queue_xmit;dev_hard_start_xmit;dev_queue_xmit_nit;packet_rcv;tpacket_rcv;sch_direct_xmit;validate_xmit_skb_list;validate_xmit_skb;netif_skb_features;ixgbe_xmit_frame_ring;swiotlb_dma_mapping_error;__dev_queue_xmit;dev_hard_start_xmit;__bpf_prog_run;__bpf_prog_run
Има многу работи овде, но главната работа е што ја наоѓаме шемата „cadvisor before ksoftirqd“ што ја видовме претходно во ICMP tracer. Што значи тоа?
Секоја линија е трага на процесорот во одреден момент во времето. Секој повик по магацинот на линијата е одделен со точка-запирка. Во средината на линиите гледаме дека syscall се нарекува: read(): .... ;do_syscall_64;sys_read; .... Така, cadvisor троши многу време на системскиот повик read()поврзани со функции mem_cgroup_* (врвот на купот на повици/крајот на линијата).
Незгодно е да се види во следењето на повик што точно се чита, па ајде да трчаме strace и да видиме што прави cadvisor и да најдеме системски повици подолги од 100ms:
theojulienne@kube-node-bad ~ $ sudo strace -p 10137 -T -ff 2>&1 | egrep '<0.[1-9]'
[pid 10436] <... futex resumed> ) = 0 <0.156784>
[pid 10432] <... futex resumed> ) = 0 <0.258285>
[pid 10137] <... futex resumed> ) = 0 <0.678382>
[pid 10384] <... futex resumed> ) = 0 <0.762328>
[pid 10436] <... read resumed> "cache 154234880nrss 507904nrss_h"..., 4096) = 658 <0.179438>
[pid 10384] <... futex resumed> ) = 0 <0.104614>
[pid 10436] <... futex resumed> ) = 0 <0.175936>
[pid 10436] <... read resumed> "cache 0nrss 0nrss_huge 0nmapped_"..., 4096) = 577 <0.228091>
[pid 10427] <... read resumed> "cache 0nrss 0nrss_huge 0nmapped_"..., 4096) = 577 <0.207334>
[pid 10411] <... epoll_ctl resumed> ) = 0 <0.118113>
[pid 10382] <... pselect6 resumed> ) = 0 (Timeout) <0.117717>
[pid 10436] <... read resumed> "cache 154234880nrss 507904nrss_h"..., 4096) = 660 <0.159891>
[pid 10417] <... futex resumed> ) = 0 <0.917495>
[pid 10436] <... futex resumed> ) = 0 <0.208172>
[pid 10417] <... futex resumed> ) = 0 <0.190763>
[pid 10417] <... read resumed> "cache 0nrss 0nrss_huge 0nmapped_"..., 4096) = 576 <0.154442>
Како што може да очекувате, овде гледаме бавни повици read(). Од содржината на операциите за читање и контекстот mem_cgroup јасно е дека овие предизвици read() упатете се на датотеката memory.stat, што покажува користење на меморијата и ограничувањата на cгрупите (технологија за изолација на ресурсите на Docker). Алатката cadvisor ја бара оваа датотека за да добие информации за користење на ресурси за контејнери. Ајде да провериме дали кернелот или кадвизорот прават нешто неочекувано:
theojulienne@kube-node-bad ~ $ time cat /sys/fs/cgroup/memory/memory.stat >/dev/null
real 0m0.153s
user 0m0.000s
sys 0m0.152s
theojulienne@kube-node-bad ~ $
Сега можеме да ја репродуцираме грешката и да разбереме дека кернелот на Линукс се соочува со патологија.
Зошто операцијата за читање е толку бавна?
Во оваа фаза, многу е полесно да се најдат пораки од други корисници за слични проблеми. Како што се испостави, во тракерот cadvisor оваа бубачка беше пријавена како , едноставно никој не забележа дека латентноста исто така случајно се рефлектира во мрежниот стек. Навистина беше забележано дека cadvisor троши повеќе време на процесорот од очекуваното, но на тоа не му беше дадено големо значење, бидејќи нашите сервери имаат многу ресурси на процесорот, така што проблемот не беше внимателно проучен.
Проблемот е што cгрупите го земаат предвид користењето на меморијата во именскиот простор (контејнер). Кога ќе излезат сите процеси во оваа cgroup, Docker ја ослободува мемориската cgroup. Сепак, „меморијата“ не е само процесна меморија. Иако самата процесна меморија повеќе не се користи, се чини дека кернелот сè уште доделува кеширани содржини, како што се заби и иноди (директориум и метаподатоци на датотеки), кои се кеширани во мемориската cгрупа. Од описот на проблемот:
зомби cгрупи: cгрупи кои немаат процеси и се избришани, но сепак имаат распределена меморија (во мојот случај, од кешот за заби, но може да се распредели и од кешот на страницата или tmpfs).
Проверката на кернелот на сите страници во кешот при ослободување на cгрупа може да биде многу бавна, така што е избран мрзливиот процес: почекајте додека овие страници повторно не се побараат, а потоа конечно исчистете ја cгрупата кога навистина е потребна меморијата. До овој момент, cgroup сè уште се зема предвид при собирање статистика.
Од гледна точка на изведбата, тие ја жртвуваа меморијата за перформанси: забрзување на почетното чистење со оставање на некоја кеширана меморија зад себе. Ова е во ред. Кога кернелот ја користи последната од кешираната меморија, cгрупата на крајот се брише, па затоа не може да се нарече „протекување“. За жал, специфичната имплементација на механизмот за пребарување memory.stat во оваа верзија на кернелот (4.9), во комбинација со огромното количество меморија на нашите сервери, значи дека е потребно многу подолго време за да се обноват најновите кеширани податоци и да се исчистат зомбите од cгрупите.
Излегува дека некои од нашите јазли имаа толку многу cgroup зомби што читањето и латентноста надминаа една секунда.
Решението за проблемот со cadvisor е веднаш да се ослободи кешот за заби/иноди низ системот, што веднаш ја елиминира доцнењето за читање, како и доцнењето на мрежата на домаќинот, бидејќи чистењето на кешот ги вклучува кешираните страници со зомби cgroup и тие исто така се ослободуваат. Ова не е решение, но ја потврдува причината за проблемот.
Се покажа дека во поновите верзии на кернелот (4.19+) перформансите на повиците се подобрени memory.stat, па префрлањето на ова јадро го реши проблемот. Во исто време, имавме алатки за откривање на проблематични јазли во кластерите на Kubernetes, благодатно исцедување и рестартирање. Ги чешлавме сите кластери, најдовме јазли со доволно висока латентност и ги рестартиравме. Ова ни даде време да го ажурираме ОС на преостанатите сервери.
Сумирајќи
Бидејќи оваа грешка ја прекина обработката на редот на RX NIC за стотици милисекунди, истовремено предизвика и висока латентност на кратки врски и латентност на средна врска, како на пример помеѓу MySQL барања и пакети за одговор.
Разбирањето и одржувањето на перформансите на најфундаменталните системи, како што е Kubernetes, е од клучно значење за доверливоста и брзината на сите услуги базирани на нив. Секој систем што го користите има придобивки од подобрувањата на перформансите на Кубернет.
Извор: www.habr.com