Prieš porą metų Kubernetes oficialiame „GitHub“ tinklaraštyje. Nuo tada ji tapo standartine paslaugų diegimo technologija. Dabar „Kubernetes“ valdo didelę dalį vidaus ir viešųjų paslaugų. Didėjant mūsų klasteriams ir griežtėjant našumo reikalavimams, pradėjome pastebėti, kad kai kurios „Kubernetes“ paslaugos retkarčiais patiria delsą, kurios negalima paaiškinti pačios programos apkrova.
Iš esmės programos patiria atsitiktinį tinklo delsą iki 100 ms ar daugiau, todėl baigiasi laikas arba bandoma pakartotinai. Buvo tikimasi, kad paslaugos galės atsakyti į užklausas daug greičiau nei per 100 ms. Bet tai neįmanoma, jei pats ryšys užtrunka tiek daug laiko. Atskirai stebėjome labai greitas „MySQL“ užklausas, kurios turėjo užtrukti milisekundes, o „MySQL“ buvo užbaigtos per milisekundes, tačiau, žiūrint iš užklausos pateikiančios programos, atsakymas užtruko 100 ms ar daugiau.
Iš karto tapo aišku, kad problema iškilo tik prisijungus prie Kubernetes mazgo, net jei skambutis buvo iš ne Kubernetes. Lengviausias būdas atkurti problemą yra bandymas , kuris veikia iš bet kurio vidinio pagrindinio kompiuterio, išbando Kubernetes paslaugą konkrečiame prievade ir retkarčiais registruoja didelę delsą. Šiame straipsnyje apžvelgsime, kaip mums pavyko nustatyti šios problemos priežastį.
Pašalinkite nereikalingą grandinės sudėtingumą, dėl kurio atsiranda gedimas
Pakartodami tą patį pavyzdį norėjome susiaurinti problemos dėmesį ir pašalinti nereikalingus sudėtingumo sluoksnius. Iš pradžių sraute tarp Vegetos ir Kubernetes ankščių buvo per daug elementų. Norėdami nustatyti gilesnę tinklo problemą, kai kurias iš jų turite atmesti.
Klientas (Vegeta) sukuria TCP ryšį su bet kuriuo klasterio mazgu. „Kubernetes“ veikia kaip perdangos tinklas (esamo duomenų centro tinklo viršuje), kuris naudoja , tai yra, jis apklijuoja dengiamojo tinklo IP paketus duomenų centro IP paketuose. Prisijungiant prie pirmojo mazgo, atliekamas tinklo adreso vertimas (NAT). Įeinantiems paketams atliekama atvirkštinė veiksmų seka. Tai sudėtinga sistema, turinti daug būsenų ir daug elementų, kurie nuolat atnaujinami ir keičiami diegiant ir perkeliant paslaugas.
Naudingumas tcpdump Vegeta teste yra uždelsimas TCP rankos paspaudimo metu (tarp SYN ir SYN-ACK). Norėdami pašalinti šį nereikalingą sudėtingumą, galite naudoti hping3 paprastiems „pingams“ su SYN paketais. Patikriname, ar atsakymo paketas vėluoja, ir iš naujo nustatome ryšį. Galime filtruoti duomenis, kad apimtų tik didesnius nei 100 ms paketus, ir gauti lengvesnį būdą atkurti problemą nei atliekant viso 7 tinklo sluoksnio testą programoje „Vegeta“. Štai Kubernetes mazgo „ping“ naudojant TCP SYN/SYN-ACK paslaugos „mazgo prievade“ (30927) 10 ms intervalais, filtruojami pagal lėčiausius atsakymus:
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
Gali iš karto padaryti pirmąjį pastebėjimą. Sprendžiant iš eilės numerių ir laiko, aišku, kad tai nėra vienkartinės spūstys. Vėlavimas dažnai kaupiasi ir galiausiai apdorojamas.
Toliau norime išsiaiškinti, kurie komponentai gali būti susiję su spūsčių atsiradimu. Galbūt tai yra keletas iš šimtų iptables taisyklių NAT? O gal yra problemų dėl IPIP tuneliavimo tinkle? Vienas iš būdų tai patikrinti – išbandyti kiekvieną sistemos žingsnį jį pašalinant. Kas atsitiks, jei pašalinsite NAT ir ugniasienės logiką, palikdami tik IPIP dalį:
Laimei, „Linux“ leidžia lengvai pasiekti IP perdangos sluoksnį tiesiogiai, jei įrenginys yra tame pačiame tinkle:
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
Sprendžiant iš rezultatų, problema vis tiek išlieka! Tai neapima iptables ir NAT. Taigi problema yra TCP? Pažiūrėkime, kaip vyksta įprastas ICMP ping:
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
Rezultatai rodo, kad problema neišnyko. Galbūt tai IPIP tunelis? Dar labiau supaprastinkime testą:
Ar visi paketai siunčiami tarp šių dviejų kompiuterių?
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
Situaciją supaprastinome dviem Kubernetes mazgais, kurie siunčia vienas kitam bet kokį paketą, net ICMP ping. Jie vis tiek mato delsą, jei tikslinė priegloba yra „bloga“ (kai kurios blogesnės nei kitos).
Dabar paskutinis klausimas: kodėl delsimas atsiranda tik kube-node serveriuose? Ir ar tai atsitinka, kai kube mazgas yra siuntėjas ar gavėjas? Laimei, tai taip pat gana lengva išsiaiškinti siunčiant paketą iš pagrindinio kompiuterio, esančio už Kubernetes ribų, bet su tuo pačiu „žinomu blogu“ gavėju. Kaip matote, problema neišnyko:
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
Tada vykdysime tas pačias užklausas iš ankstesnio šaltinio kube mazgo į išorinį pagrindinį kompiuterį (kuris neįtraukia šaltinio pagrindinio kompiuterio, nes ping apima ir RX, ir TX komponentus):
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
Išnagrinėję delsos paketų fiksavimus, gavome papildomos informacijos. Tiksliau, kad siuntėjas (apačioje) mato šį skirtąjį laiką, o gavėjas (viršuje) ne – žr. stulpelį Delta (sekundėmis):
Be to, jei pažvelgsite į TCP ir ICMP paketų eilės skirtumą (pagal eilės numerius) gavėjo pusėje, ICMP paketai visada atkeliauja ta pačia seka, kuria buvo išsiųsti, bet skirtingu laiku. Tuo pačiu metu TCP paketai kartais persipina, o kai kurie iš jų užstringa. Visų pirma, jei išnagrinėsite SYN paketų prievadus, jie yra tvarkingi siuntėjo pusėje, bet ne gavėjo pusėje.
Yra subtilus skirtumas kaip Šiuolaikiniai serveriai (kaip ir mūsų duomenų centre esantys) apdoroja paketus, kuriuose yra TCP arba ICMP. Kai gaunamas paketas, tinklo adapteris „maišo jį per ryšį“, tai yra, jis bando suskaidyti ryšius į eiles ir kiekvieną eilę nusiųsti į atskirą procesoriaus branduolį. TCP atveju ši maiša apima šaltinio ir paskirties IP adresą ir prievadą. Kitaip tariant, kiekvienas ryšys maišomas (galimai) skirtingai. ICMP atveju maišoma tik IP adresai, nes nėra prievadų.
Kitas naujas pastebėjimas: šiuo laikotarpiu matome ICMP vėlavimą visuose ryšiuose tarp dviejų pagrindinių kompiuterių, bet TCP ne. Tai rodo, kad priežastis greičiausiai yra susijusi su RX eilės maiša: spūstis beveik neabejotinai kyla apdorojant RX paketus, o ne siunčiant atsakymus.
Tai pašalina paketų siuntimą iš galimų priežasčių sąrašo. Dabar žinome, kad kai kurių kube mazgo serverių paketų apdorojimo problema yra gavimo pusėje.
Paketų apdorojimo Linux branduolyje supratimas
Norėdami suprasti, kodėl problema iškyla kai kurių kube mazgų serverių imtuve, pažiūrėkime, kaip Linux branduolys apdoroja paketus.
Grįžtant prie paprasčiausio tradicinio įgyvendinimo, tinklo plokštė priima paketą ir siunčia Linux branduolį, kad yra paketas, kurį reikia apdoroti. Branduolys sustabdo kitą darbą, perjungia kontekstą į pertraukimų tvarkyklę, apdoroja paketą ir grįžta prie dabartinių užduočių.
Šis konteksto perjungimas yra lėtas: devintajame dešimtmetyje 10 Mbps tinklo plokštėse delsos galbūt nebuvo pastebimos, tačiau šiuolaikinėse 90G kortelėse, kurių didžiausias pralaidumas yra 10 milijonų paketų per sekundę, kiekvienas mažo aštuonių branduolių serverio branduolys gali būti pertrauktas milijonus kartų. kartų per sekundę.
Kad nebūtų nuolat tvarkomi pertraukimai, prieš daugelį metų buvo pridėta Linux : Tinklo API, kurią naudoja visos šiuolaikinės tvarkyklės, kad pagerintų našumą esant dideliam greičiui. Esant mažam greičiui, branduolys vis tiek gauna pertraukimus iš tinklo plokštės senuoju būdu. Kai gaunama pakankamai paketų, kurie viršija slenkstį, branduolys išjungia pertraukimus ir pradeda apklausti tinklo adapterį ir rinkti paketus dalimis. Apdorojimas atliekamas softirq, tai yra, in po sistemos iškvietimų ir aparatinės įrangos pertraukimų, kai branduolys (priešingai nei vartotojo erdvė) jau veikia.
Tai daug greičiau, bet sukelia kitokią problemą. Jei paketų yra per daug, tada visas laikas praleidžiamas paketams iš tinklo plokštės apdoroti, o vartotojo erdvės procesai nespėja iš tikrųjų ištuštinti šių eilių (skaitymas iš TCP jungčių ir pan.). Galiausiai eilės užsipildo ir pradedame mesti paketus. Bandydamas rasti pusiausvyrą, branduolys nustato biudžetą didžiausiam paketų, apdorojamų softirq kontekste, skaičiui. Viršijus šį biudžetą, pažadinama atskira gija ksoftirqd (vieną iš jų pamatysite ps vienam branduoliui), kuris tvarko šiuos „softirq“ už įprasto syscall / pertraukimo kelio. Ši gija suplanuota naudojant standartinį proceso planavimo priemonę, kuri bando teisingai paskirstyti išteklius.
Ištyrę, kaip branduolys apdoroja paketus, matote, kad yra tam tikra perkrovos tikimybė. Jei softirq skambučiai priimami rečiau, paketai turės kurį laiką palaukti, kol bus apdoroti tinklo plokštės RX eilėje. Taip gali nutikti dėl kažkokios užduoties, blokuojančios procesoriaus šerdį, arba dėl kažko kito, kuris neleidžia branduoliui paleisti softirq.
Apdorojimo susiaurinimas iki esmės arba metodo
Softirq vėlavimai kol kas yra tik spėjimas. Bet tai prasminga, ir mes žinome, kad matome kažką labai panašaus. Taigi kitas žingsnis – patvirtinti šią teoriją. Ir jei tai pasitvirtins, raskite vėlavimo priežastį.
Grįžkime prie lėtųjų paketų:
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
Kaip aptarta anksčiau, šie ICMP paketai sumaišomi į vieną RX NIC eilę ir apdorojami vienu procesoriaus branduoliu. Jei norime suprasti, kaip veikia Linux, pravartu žinoti, kur (kuriame CPU branduolyje) ir kaip (softirq, ksoftirqd) šie paketai apdorojami, kad būtų galima sekti procesą.
Dabar atėjo laikas naudoti įrankius, leidžiančius stebėti „Linux“ branduolį realiuoju laiku. Čia mes panaudojome . Šis įrankių rinkinys leidžia rašyti nedideles C programas, kurios prikabina savavališkas branduolio funkcijas ir buferiuoja įvykius į vartotojo erdvės Python programą, kuri gali juos apdoroti ir grąžinti jums rezultatą. Savavališkų funkcijų įtraukimas į branduolį yra sudėtingas verslas, tačiau įrankis sukurtas maksimaliam saugumui ir yra skirtas tiksliai nustatyti tokias gamybos problemas, kurios nėra lengvai atkuriamos bandymo ar kūrimo aplinkoje.
Planas čia paprastas: žinome, kad branduolys apdoroja šiuos ICMP pingus, todėl užkabinsime branduolio funkciją , kuris priima įeinantį ICMP aido užklausos paketą ir inicijuoja ICMP aido atsako siuntimą. Mes galime identifikuoti paketą padidindami icmp_seq skaičių, kuris rodo hping3 didesnis.
Kodas atrodo sudėtinga, bet tai nėra taip baisu, kaip atrodo. Funkcija icmp_echo perduoda struct sk_buff *skb: Tai paketas su „aido užklausa“. Galime sekti, ištraukti seką echo.sequence (kuris lyginamas su icmp_seq pateikė hping3 выше) ir nusiųskite į vartotojo erdvę. Taip pat patogu užfiksuoti esamo proceso pavadinimą / ID. Žemiau pateikiami rezultatai, kuriuos matome tiesiogiai, kai branduolys apdoroja paketus:
TGID PID PROCESO PAVADINIMAS ICMP_SEQ 0 0 keitiklis / 11 770 0 0 keitiklis / 11 771 0 0 keitiklis / 11 772 0 0 keitiklis / 11 773 0 0 keitiklis / 11 774 20041 20086 Prometėjas 775 0 0 keitiklis / 11 776 0 0 keitiklis / 11 777 0 0 keitiklis / 11 778 4512 4542 spaudai-pranešimai-s 779
Čia reikia pažymėti, kad kontekste softirq procesai, kurie iškvietė sistemą, bus rodomi kaip „procesai“, nors iš tikrųjų branduolys saugiai apdoroja paketus branduolio kontekste.
Naudodami šį įrankį galime susieti konkrečius procesus su konkrečiais paketais, kurie rodo delsą hping3. Padarykime tai paprasta grep apie tam tikras vertes icmp_seq. Paketai, atitinkantys aukščiau nurodytas icmp_seq reikšmes, buvo pažymėti kartu su jų RTT, kurį stebėjome aukščiau (skliausteliuose yra numatomos RTT reikšmės paketams, kuriuos išfiltravome dėl mažesnių nei 50 ms RTT verčių):
TGID PID PROCESO PAVADINIMAS ICMP_SEQ ** RTT -- 10137 10436 cadvisor 1951 m 10137 10436 cadvisor 1952 m 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 ** (49 ms) 76 76 ksoftirqd/11 1959 ** (39 ms) 76 76 ksoftirqd/11 1960 ** (29 ms) 76 76 ksoftirqd/11 1961 ** (19 ms) 76 76 ksoftirqd/11 1962 ** (9 ms) -- 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 ** (45 ms) 76 76 ksoftirqd/11 2074 ** (35 ms) 76 76 ksoftirqd/11 2075 ** (25 ms) 76 76 ksoftirqd/11 2076 ** (15 ms) 76 76 ksoftirqd/11 2077 ** (5 ms)
Rezultatai mums pasako keletą dalykų. Pirma, visi šie paketai apdorojami atsižvelgiant į kontekstą ksoftirqd/11. Tai reiškia, kad šios konkrečios mašinų poros ICMP paketai buvo sumaišyti iki 11 branduolio priėmimo gale. Taip pat matome, kad kai tik užstringa, yra paketų, kurie apdorojami sistemos skambučio kontekste cadvisor. Tada ksoftirqd perima užduotį ir apdoroja sukauptą eilę: tiksliai tiek paketų, kiek susikaupė po cadvisor.
Tai, kad iš karto prieš tai visada veikia cadvisor, reiškia jo įsitraukimą į problemą. Ironiška, tikslas - „analizuokite išteklių naudojimą ir veikiančių sudėtinių rodinių našumo charakteristikas“, o ne sukelkite šią našumo problemą.
Kaip ir kiti konteinerių aspektai, visi šie įrankiai yra labai pažangūs ir gali susidurti su veikimo problemomis tam tikromis nenumatytomis aplinkybėmis.
Ką daro cadvisor, kuris sulėtina paketų eilę?
Dabar mes gana gerai suprantame, kaip įvyksta gedimas, koks procesas ją sukelia ir kuriame procesoriuje. Matome, kad dėl sunkaus blokavimo „Linux“ branduolys neturi laiko planuoti ksoftirqd. Ir matome, kad paketai apdorojami kontekste cadvisor. Logiška taip manyti cadvisor paleidžia lėtą syscall, po kurio apdorojami visi tuo metu sukaupti paketai:
Tai teorija, bet kaip ją patikrinti? Tai, ką galime padaryti, yra atsekti procesoriaus branduolį viso proceso metu, rasti tašką, kur paketų skaičius viršija biudžetą ir iškviečiamas ksoftirqd, o tada pažvelgti šiek tiek atgal, kad pamatytumėte, kas tiksliai veikė procesoriaus branduolyje prieš pat tą tašką. . Tai tarsi procesoriaus rentgenas kas kelias milisekundes. Tai atrodys maždaug taip:
Patogiai visa tai galima padaryti naudojant esamas priemones. Pavyzdžiui, tikrina tam tikrą procesoriaus branduolį nurodytu dažniu ir gali sugeneruoti skambučių į veikiančią sistemą grafiką, įskaitant vartotojo erdvę ir Linux branduolį. Galite paimti šį įrašą ir apdoroti jį naudodami nedidelę programos šakutę iš Brendano Greggo, kuris išsaugo krūvos pėdsakų tvarką. Galime išsaugoti vienos eilutės dėklo pėdsakus kas 1 ms, o tada paryškinti ir išsaugoti pavyzdį likus 100 milisekundžių, kol pėdsakas pasiekia 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
Štai rezultatai:
(сотни следов, которые выглядят похожими)
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
Čia yra daug dalykų, bet svarbiausia yra tai, kad rasime šabloną „cadvisor before ksoftirqd“, kurį matėme anksčiau ICMP sekimo programoje. Ką tai reiškia?
Kiekviena eilutė yra procesoriaus pėdsakas tam tikru momentu. Kiekvienas iškvietimas eilutėje yra atskirtas kabliataškiu. Eilučių viduryje matome vadinamą syscall: read(): .... ;do_syscall_64;sys_read; .... Taigi „cadvisor“ praleidžia daug laiko sistemos skambučiui read()susiję su funkcijomis mem_cgroup_* (skambučio krūvos viršus / linijos pabaiga).
Nepatogu skambučio sekoje matyti, kas tiksliai skaitoma, todėl paleiskite strace ir pažiūrėkime, ką daro cadvisor, ir suraskime ilgesnius nei 100 ms sistemos skambučius:
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>
Kaip ir galima tikėtis, čia matome lėtus skambučius read(). Iš skaitymo operacijų turinio ir konteksto mem_cgroup aišku, kad šie iššūkiai read() kreiptis į failą memory.stat, kuris rodo atminties naudojimą ir cgroup ribas („Docker“ išteklių izoliavimo technologija). Cadvisor įrankis pateikia šio failo užklausą, kad gautų konteinerių išteklių naudojimo informaciją. Patikrinkime, ar branduolys arba cadvisor nedaro ką nors netikėto:
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 ~ $
Dabar galime atkurti klaidą ir suprasti, kad Linux branduolys susiduria su patologija.
Kodėl skaitymo operacija tokia lėta?
Šiame etape daug lengviau rasti kitų vartotojų pranešimus apie panašias problemas. Kaip paaiškėjo, cadvisor sekimo priemonėje apie šią klaidą pranešta kaip , tiesiog niekas nepastebėjo, kad delsa taip pat atsitiktinai atsispindi tinklo krūvoje. Tikrai buvo pastebėta, kad cadvisor eikvoja daugiau procesoriaus laiko nei tikėtasi, tačiau tai nebuvo sureikšminta, kadangi mūsų serveriai turi daug procesoriaus resursų, todėl problema nebuvo atidžiai išnagrinėta.
Problema ta, kad cgroups atsižvelgia į atminties naudojimą vardų erdvėje (konteineryje). Kai visi procesai šioje cgrupėje baigiami, „Docker“ išleidžia atminties cgrupę. Tačiau „atmintis“ nėra tik proceso atmintis. Nors pati proceso atmintis nebenaudojama, atrodo, kad branduolys vis tiek priskiria talpykloje saugomą turinį, pvz., dentrius ir inodes (katalogų ir failų metaduomenis), kurie saugomi atminties cgrupėje. Iš problemos aprašymo:
zombie cgroups: cgrupės, kurios neturi procesų ir buvo ištrintos, bet vis dar turi skirtą atmintį (mano atveju iš dentry cache, bet ją galima skirti ir iš puslapio talpyklos arba tmpfs).
Branduolis tikrina visus talpykloje esančius puslapius atlaisvinant cgroup gali būti labai lėtas, todėl pasirenkamas tingus procesas: palaukite, kol šie puslapiai bus vėl užklausti, o tada galiausiai išvalykite cgroup, kai iš tikrųjų prireiks atminties. Iki šio momento renkant statistiką vis dar atsižvelgiama į cgroup.
Našumo požiūriu jie paaukojo atmintį dėl našumo: pagreitino pradinį valymą, palikdami šiek tiek talpyklos atminties. Tai yra gerai. Kai branduolys naudoja paskutinę talpykloje esančią atmintį, cgrupė galiausiai išvaloma, todėl to negalima pavadinti „nutekėjimu“. Deja, konkretus paieškos mechanizmo įgyvendinimas memory.stat Šioje branduolio versijoje (4.9) kartu su didžiuliu atminties kiekiu mūsų serveriuose reiškia, kad atstatyti naujausius talpyklos duomenis ir išvalyti cgroup zombius užtrunka daug ilgiau.
Pasirodo, kai kuriuose mūsų mazguose buvo tiek daug cgroup zombių, kad skaitymas ir delsa viršijo sekundę.
„Cadvisor“ problemos sprendimas yra nedelsiant atlaisvinti „dentries“ / „inode“ talpyklas visoje sistemoje, o tai iš karto pašalina skaitymo delsą ir tinklo delsą pagrindiniame kompiuteryje, nes išvalius talpyklą įjungiami talpykloje saugomi cgroup zombių puslapiai ir jie taip pat atlaisvinami. Tai nėra sprendimas, bet patvirtina problemos priežastį.
Paaiškėjo, kad naujesnėse branduolio versijose (4.19+) skambučių našumas buvo pagerintas memory.stat, todėl perėjus prie šio branduolio problema išspręsta. Tuo pačiu metu turėjome įrankius, leidžiančius aptikti probleminius mazgus Kubernetes klasteriuose, gražiai juos nusausinti ir paleisti iš naujo. Mes sušukavome visas grupes, radome mazgus su pakankamai dideliu delsimu ir juos paleidome iš naujo. Tai suteikė mums laiko atnaujinti OS likusiuose serveriuose.
Sumavimas
Kadangi ši klaida šimtams milisekundžių sustabdė RX NIC eilės apdorojimą, ji vienu metu sukėlė tiek didelį trumpų ryšių delsą, tiek vidutinį ryšio delsą, pvz., tarp MySQL užklausų ir atsako paketų.
Norint užtikrinti visų jomis pagrįstų paslaugų patikimumą ir greitį, labai svarbu suprasti ir palaikyti svarbiausių sistemų, tokių kaip „Kubernetes“, veikimą. Kiekviena jūsų valdoma sistema turi „Kubernetes“ našumo patobulinimų.
Šaltinis: www.habr.com