Pipila ka tuig ang milabay Kubernetes nahisgotan na sa opisyal nga GitHub blog. Sukad niadto, nahimo na kini nga sumbanan nga teknolohiya alang sa pag-deploy sa mga serbisyo. Ang Kubernetes karon nagdumala sa usa ka mahinungdanong bahin sa internal ug publiko nga mga serbisyo. Samtang nagkadako ang among mga pundok ug nahimong mas estrikto ang mga kinahanglanon sa performance, among namatikdan nga ang pipila ka mga serbisyo sa Kubernetes panalagsa nga nakasinati og latency nga dili mapasabot sa load sa aplikasyon mismo.

Sa esensya, ang mga aplikasyon makasinati ug random network latency hangtod sa 100ms o labaw pa, nga moresulta sa mga timeout o pagsulay pag-usab. Ang mga serbisyo gilauman nga makatubag sa mga hangyo nga labi ka paspas kaysa 100ms. Apan imposible kini kung ang koneksyon mismo nagkinahanglan og daghang oras. Gilain, among naobserbahan ang paspas kaayo nga mga pangutana sa MySQL nga kinahanglan nga millisecond, ug ang MySQL nahuman sa millisecond, apan gikan sa perspektibo sa paghangyo nga aplikasyon, ang tubag gikuha 100 ms o labaw pa.

Diha-diha dayon nahimong klaro nga ang problema nahitabo lamang sa dihang nagkonektar sa usa ka Kubernetes node, bisan kung ang tawag gikan sa gawas sa Kubernetes. Ang labing sayon nga paagi sa pag-reproduce sa problema mao ang pagsulay Vegeta, nga nagdagan gikan sa bisan unsang internal nga host, nagsulay sa serbisyo sa Kubernetes sa usa ka piho nga pantalan, ug panagsa nga nagrehistro sa taas nga latency. Niini nga artikulo, atong tan-awon kung giunsa naton masubay ang hinungdan sa kini nga problema.

Pagwagtang sa wala kinahanglana nga pagkakomplikado sa kadena nga mosangpot sa kapakyasan

Pinaagi sa pagkopya sa parehas nga pananglitan, gusto namon nga makit-an ang pokus sa problema ug tangtangon ang dili kinahanglan nga mga layer sa pagkakomplikado. Sa sinugdan, adunay daghan kaayong mga elemento sa dagan tali sa Vegeta ug sa mga pod sa Kubernetes. Aron mahibal-an ang usa ka mas lawom nga problema sa network, kinahanglan nimo nga isalikway ang pipila niini.

Ang kliyente (Vegeta) nagmugna og koneksyon sa TCP sa bisan unsang node sa cluster. Ang Kubernetes naglihok isip usa ka overlay network (sa ibabaw sa kasamtangan nga data center network) nga naggamit IPIP, sa ato pa, gi-encapsulate niini ang mga IP packet sa overlay network sulod sa mga IP packet sa data center. Kung nagkonektar sa una nga node, ang paghubad sa adres sa network gihimo Paghubad sa Address sa Network (NAT) stateful sa paghubad sa IP address ug port sa Kubernetes node ngadto sa IP address ug port sa overlay network (partikular, ang pod nga adunay aplikasyon). Alang sa umaabot nga mga pakete, ang reverse sequence sa mga aksyon gihimo. Kini usa ka komplikado nga sistema nga adunay daghang estado ug daghang mga elemento nga kanunay nga gi-update ug gibag-o samtang ang mga serbisyo gipakatap ug gibalhin.

Gamit tcpdump sa pagsulay sa Vegeta adunay usa ka paglangan sa panahon sa TCP handshake (tali sa SYN ug SYN-ACK). Aron makuha kining wala kinahanglana nga pagkakomplikado, mahimo nimong gamiton hping3 alang sa yano nga "pings" nga adunay mga pakete sa SYN. Atong susihon kung adunay usa ka paglangan sa tubag nga pakete, ug dayon i-reset ang koneksyon. Mahimo natong i-filter ang mga datos aron maapil lamang ang mga pakete nga labaw sa 100ms ug makakuha og mas sayon nga paagi sa pag-reproduce sa problema kay sa bug-os nga network layer 7 nga pagsulay sa Vegeta. Ania ang Kubernetes node "pings" gamit ang TCP SYN/SYN-ACK sa serbisyo nga "node port" (30927) sa 10ms intervals, gisala sa pinakahinay nga mga tubag:

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

Makahimo dayon sa unang obserbasyon. Kung hukman ang mga numero sa pagkasunod-sunod ug oras, klaro nga dili kini usa ka higayon nga paghuot. Ang paglangan kanunay nga natipon ug sa katapusan maproseso.

Sunod, gusto namon mahibal-an kung unsang mga sangkap ang mahimo’g maapil sa pagkahitabo sa paghuot. Tingali kini ang pipila sa gatusan nga mga lagda sa iptables sa NAT? O aduna bay mga problema sa IPIP tunneling sa network? Usa ka paagi sa pagsusi niini mao ang pagsulay sa matag lakang sa sistema pinaagi sa pagwagtang niini. Unsa ang mahitabo kung imong tangtangon ang NAT ug firewall logic, gibiyaan lamang ang bahin sa IPIP:

Maayo na lang, gipasayon sa Linux ang pag-access sa IP overlay layer direkta kon ang makina anaa sa samang network:

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

Sa paghukom sa mga resulta, ang problema nagpabilin gihapon! Kini wala maglakip sa iptables ug NAT. Busa ang problema mao ang TCP? Atong tan-awon kung giunsa ang usa ka regular nga 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

Ang mga resulta nagpakita nga ang problema wala mawala. Tingali kini usa ka tunel sa IPIP? Atong pasimplehon pa ang pagsulay:

Ang tanan ba nga mga pakete gipadala tali niining duha ka mga host?

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

Gipasimple namo ang sitwasyon sa duha ka Kubernetes node nga nagpadala sa usag usa sa bisan unsang pakete, bisan usa ka ICMP ping. Nakita gihapon nila ang latency kung "daotan" ang target host (ang uban mas grabe kaysa sa uban).

Karon ang katapusang pangutana: ngano nga ang paglangan mahitabo ra sa mga server sa kube-node? Ug mahitabo ba kini kung ang kube-node mao ang nagpadala o ang tigdawat? Maayo na lang, dali ra usab kini mahibal-an pinaagi sa pagpadala usa ka pakete gikan sa usa ka host sa gawas sa Kubernetes, apan adunay parehas nga "nailhan nga dili maayo" nga nakadawat. Sama sa imong nakita, ang problema wala mawala:

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

Atong ipadagan ang parehas nga mga hangyo gikan sa naunang tinubdan nga kube-node ngadto sa eksternal nga host (nga wala maglakip sa tinubdan nga host tungod kay ang ping naglakip sa usa ka RX ug TX component):

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

Pinaagi sa pagsusi sa latency packet captures, nakakuha kami og dugang nga impormasyon. Sa piho, nga ang nagpadala (ubos) nakakita niini nga timeout, apan ang nakadawat (ibabaw) dili - tan-awa ang Delta column (sa mga segundo):

Dugang pa, kon imong tan-awon ang kalainan sa han-ay sa TCP ug ICMP packets (pinaagi sa sequence number) sa recipient side, ang ICMP packets kanunay moabot sa samang han-ay diin sila gipadala, apan lainlain ang timing. Sa samang higayon, ang mga packet sa TCP usahay mag-interleave, ug ang uban niini ma-stuck. Sa partikular, kung imong susihon ang mga pantalan sa mga pakete sa SYN, naa sila sa kilid sa nagpadala, apan dili sa kilid sa tigdawat.

Adunay usa ka gamay nga kalainan kung giunsa network card modernong mga server (sama niadtong anaa sa among data center) nagproseso sa mga packet nga adunay TCP o ICMP. Sa diha nga ang usa ka pakete moabut, ang network adapter "hash kini matag koneksyon", nga mao, kini mosulay sa pagbungkag sa mga koneksyon ngadto sa mga pila ug ipadala ang matag pila ngadto sa usa ka linain nga processor core. Alang sa TCP, kini nga hash naglakip sa tinubdan ug destinasyon nga IP address ug pantalan. Sa laing pagkasulti, ang matag koneksyon gi-hash (potensyal) nga lahi. Alang sa ICMP, ang mga IP address ra ang gi-hash, tungod kay wala’y mga pantalan.

Laing bag-ong obserbasyon: niining panahona atong makita ang ICMP nga mga paglangan sa tanang komunikasyon tali sa duha ka host, apan ang TCP wala. Gisultihan kami niini nga ang hinungdan lagmit nga adunay kalabotan sa RX queue hashing: ang paghuot hapit sigurado sa pagproseso sa mga pakete sa RX, dili sa pagpadala sa mga tubag.

Giwagtang niini ang pagpadala sa mga pakete gikan sa lista sa posible nga mga hinungdan. Nahibal-an na namon karon nga ang problema sa pagproseso sa packet naa sa bahin sa pagdawat sa pipila nga mga server sa kube-node.

Pagsabot sa pagproseso sa packet sa Linux kernel

Aron masabtan kung ngano nga ang problema nahitabo sa tigdawat sa pipila nga mga server sa kube-node, tan-awon naton kung giunsa ang pagproseso sa mga pakete sa Linux kernel.

Pagbalik sa pinakasimple nga tradisyonal nga pagpatuman, ang network card nakadawat sa pakete ug nagpadala makabalda ang Linux kernel nga adunay usa ka pakete nga kinahanglan iproseso. Gipahunong sa kernel ang ubang trabaho, gibalhin ang konteksto sa tigdumala sa interrupt, giproseso ang pakete, ug unya mibalik sa karon nga mga buluhaton.

Kini nga pagbalhin sa konteksto hinay: ang latency tingali dili mamatikdan sa 10Mbps nga mga network card sa '90s, apan sa modernong 10G nga mga kard nga adunay maximum nga throughput nga 15 milyon nga mga pakete matag segundo, ang matag kinauyokan sa usa ka gamay nga walo ka-core server mahimong mabalda milyon-milyon. sa mga panahon matag segundo.

Aron dili kanunay pagdumala sa mga interrupts, daghang tuig na ang milabay gidugang sa Linux NAPI: Network API nga gigamit sa tanang modernong mga drayber aron mapausbaw ang performance sa taas nga tulin. Sa mubu nga katulin ang kernel makadawat gihapon og mga interrupt gikan sa network card sa daan nga paagi. Sa higayon nga moabut ang igo nga mga pakete nga molapas sa threshold, ang kernel nag-disable sa mga interrupts ug sa baylo magsugod sa pagboto sa network adapter ug pagkuha sa mga pakete sa mga tipak. Ang pagproseso gihimo sa softirq, nga mao, sa konteksto sa software interrupts pagkahuman sa mga tawag sa sistema ug paghunong sa hardware, kung ang kernel (sukwahi sa wanang sa gumagamit) nagdagan na.

Kini labi ka paspas, apan hinungdan sa lahi nga problema. Kung adunay daghan kaayo nga mga pakete, nan ang tanan nga oras gigugol sa pagproseso sa mga pakete gikan sa network card, ug ang mga proseso sa wanang sa gumagamit wala’y oras sa aktuwal nga paghaw-as niini nga mga pila (pagbasa gikan sa mga koneksyon sa TCP, ug uban pa). Sa kadugayan napuno ang mga pila ug nagsugod kami sa paghulog sa mga pakete. Sa pagsulay sa pagpangita og balanse, ang kernel nagtakda og badyet alang sa pinakataas nga gidaghanon sa mga pakete nga giproseso sa softirq nga konteksto. Kung malapas na kini nga badyet, usa ka lahi nga hilo ang mapukaw ksoftirqd (makita nimo ang usa kanila sa ps kada core) nga nagdumala niining mga softirqs gawas sa normal nga syscall/interrupt nga dalan. Ang kini nga hilo gieskedyul gamit ang standard nga scheduler sa proseso, nga misulay sa paggahin ug mga kapanguhaan sa patas nga paagi.

Sa pagtuon kung giunsa ang pagproseso sa kernel sa mga pakete, imong makita nga adunay usa ka piho nga posibilidad sa paghuot. Kung ang mga tawag sa softirq dili kaayo madawat, ang mga pakete kinahanglan maghulat sa pipila ka oras aron maproseso sa RX queue sa network card. Mahimo kini tungod sa pipila ka buluhaton nga nag-ali sa core sa processor, o adunay lain nga nagpugong sa kinauyokan sa pagdagan sa softirq.

Pagkunhod sa pagproseso hangtod sa kinauyokan o pamaagi

Ang mga paglangan sa Softirq usa lang ka panaghap sa pagkakaron. Apan kini makatarunganon, ug nahibal-an namon nga kami nakakita og usa ka butang nga parehas kaayo. Busa ang sunod nga lakang mao ang pagkumpirma niini nga teorya. Ug kung kini napamatud-an, nan pangitaa ang hinungdan sa mga paglangan.

Balikan nato ang atong hinay nga mga pakete:

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

Sama sa gihisgutan sa sayo pa, kini nga mga pakete sa ICMP gi-hash ngadto sa usa ka RX NIC queue ug giproseso sa usa ka CPU core. Kung gusto namon nga masabtan kung giunsa ang paglihok sa Linux, mapuslanon nga mahibal-an kung diin (kung diin ang CPU core) ug kung giunsa (softirq, ksoftirqd) giproseso kini nga mga pakete aron masubay ang proseso.

Karon na ang panahon sa paggamit sa mga himan nga nagtugot kanimo sa pag-monitor sa Linux kernel sa tinuud nga oras. Dinhi among gigamit bcc. Kini nga hugpong sa mga himan nagtugot kanimo sa pagsulat sa gagmay nga mga programa sa C nga nag-hook sa arbitraryong mga function sa kernel ug nag-buffer sa mga panghitabo ngadto sa usa ka user-space nga Python nga programa nga makaproseso niini ug ibalik ang resulta kanimo. Ang pag-hook sa arbitraryong mga gimbuhaton sa kernel usa ka komplikado nga butang, apan ang utility gidisenyo alang sa labing kataas nga seguridad ug gidesinyo aron masubay ang eksakto nga klase sa mga isyu sa produksiyon nga dili dali nga makopya sa usa ka pagsulay o pag-uswag nga palibot.

Ang plano dinhi yano ra: nahibal-an namon nga giproseso sa kernel kini nga mga ping sa ICMP, mao nga magbutang kami usa ka kaw-it sa function sa kernel icmp_echo, nga modawat sa umaabot nga ICMP echo request packet ug magsugod sa pagpadala ug ICMP echo response. Kita makaila sa usa ka pakete pinaagi sa pagdugang sa icmp_seq numero, nga nagpakita hping3 mas taas.

code bcc nga script komplikado tan-awon, apan kini dili ingon ka makahadlok ingon nga kini daw. Kalihokan icmp_echo nagpadala struct sk_buff *skb: Kini usa ka pakete nga adunay "echo request". Masubay nato kini, ibira ang pagkasunodsunod echo.sequence (nga itandi sa icmp_seq pinaagi sa hping3 выше), ug ipadala kini sa user space. Kombenyente usab ang pagkuha sa karon nga ngalan/id sa proseso. Sa ubos mao ang mga resulta nga atong makita direkta samtang ang kernel nagproseso sa mga pakete:

TGID PID PROCESS NAME ICMP_SEQ 0 0 swapper/11 770 0 0 swapper/11 771 0 0 swapper/11 772 0 0 swapper/11 773 0 0 swapper/11 774 20041 20086 swapper/775 swapper/0 0 11 776 swapper/0 0 11 777 spokes-report-s 0

Kini kinahanglan nga matikdan dinhi nga sa konteksto softirq Ang mga proseso nga naghimo sa mga tawag sa sistema makita nga "mga proseso" kung sa tinuud kini ang kernel nga luwas nga nagproseso sa mga pakete sa konteksto sa kernel.

Uban niini nga himan mahimo natong i-associate ang mga piho nga proseso sa piho nga mga pakete nga nagpakita sa pagkalangan sa hping3. Himoon nato nga simple grep sa kini nga pagdakop alang sa pipila nga mga kantidad icmp_seq. Ang mga pakete nga katumbas sa mga kantidad sa icmp_seq sa ibabaw nakit-an kauban ang ilang RTT nga among naobserbahan sa ibabaw (sa parentesis mao ang gipaabut nga mga kantidad sa RTT alang sa mga pakete nga among gisala tungod sa mga kantidad sa RTT nga wala’y 50 ms):

TGID PID PROCESS NAME ICMP_SEQ ** RTT -- 10137 10436 cadvisor 1951 10137 10436 cadvisor 1952 76 76 ksoftirqd/11 1953 ** 99ms 76 76 ksoftirqd 11 1954 ksoftirqd 89 76 ** 76ms 11 1955 ksoftirqd/79 76 ** 76ms 11 1956 ksoftirqd/69 76 ** 76ms 11 1957 ksoftirqd/59 76 ** (76ms) 11 1958 ksoftirqd/49 76 ** (76ms) 11 1959 ksoftirqd/39 ** 76 76 ksoftirqd/11 / 1960 29 ** (76ms) 76 11 ksoftirqd/1961 19 ** (76ms) -- 76 11 cadvisor 1962 9 10137 cadvisor 10436 2068 10137 ksoftirqd/10436 **2069 ksoftirqd/76 **76 11 ** 2070ms 75 76 ksoftirqd/ 76 11 ** 2071ms 65 76 ksoftirqd/76 11 ** (2072ms) 55 76 ksoftirqd/76 11 ** (2073ms) 45 76 ksoftirqd/76 11 ** (2074ms) 35 ms) ) 76 76 ksoftirqd/11 2075 ** (25ms)

Ang mga resulta nagsulti kanato sa daghang mga butang. Una, kining tanan nga mga pakete giproseso sa konteksto ksoftirqd/11. Kini nagpasabot nga alang niining partikular nga pares sa mga makina, ang mga pakete sa ICMP gi-hash ngadto sa kinauyokan 11 sa katapusan nga pagdawat. Nakita usab namon nga kung adunay usa ka jam, adunay mga pakete nga giproseso sa konteksto sa tawag sa sistema cadvisor. Unya ksoftirqd mopuli sa buluhaton ug moproseso sa natipon nga pila: eksakto ang gidaghanon sa mga pakete nga natipon pagkahuman cadvisor.

Ang kamatuoran nga sa wala pa kini kanunay nga molihok cadvisor, nagpasabot sa iyang pagkalambigit sa problema. Katingad-an, ang katuyoan cadvisor - "I-analisa ang paggamit sa kapanguhaan ug mga kinaiya sa pasundayag sa nagdagan nga mga sudlanan" kaysa hinungdan sa kini nga isyu sa pasundayag.

Sama sa ubang mga aspeto sa mga sudlanan, kini tanan labi ka abante nga mga himan ug mapaabut nga makasinati mga isyu sa pasundayag sa ilawom sa pipila nga wala damha nga mga kahimtang.

Unsay gibuhat sa cadvisor nga nagpahinay sa packet queue?

Kami karon adunay usa ka maayo nga pagsabut kung giunsa ang pagkahagsa, unsa nga proseso ang hinungdan niini, ug kung diin ang CPU. Nakita namon nga tungod sa lisud nga pag-block, ang kernel sa Linux wala’y oras sa pag-iskedyul ksoftirqd. Ug nakita namon nga ang mga pakete giproseso sa konteksto cadvisor. Makataronganon ang paghunahuna niana cadvisor naglansad sa usa ka hinay nga syscall, pagkahuman ang tanan nga mga pakete nga natipon nianang panahona giproseso:

Kini usa ka teorya, apan unsaon pagsulay niini? Unsa ang atong mahimo mao ang pagsubay sa CPU core sa tibuok niini nga proseso, pangitaa ang punto diin ang gidaghanon sa mga pakete molapas sa badyet ug ksoftirqd gitawag, ug unya tan-aw sa usa ka gamay nga balik aron makita kung unsa gayud ang nagdagan sa CPU core sa wala pa ang punto. . Kini sama sa x-raying sa CPU matag pipila ka milliseconds. Kini tan-awon sama niini:

Sayon, kining tanan mahimo gamit ang naa na nga mga himan. Pananglitan, perf nga rekord nagsusi sa gihatag nga CPU core sa usa ka espesipikong frequency ug makamugna og eskedyul sa mga tawag sa nagdagan nga sistema, lakip ang user space ug ang Linux kernel. Mahimo nimong kuhaon kini nga rekord ug iproseso kini gamit ang gamay nga tinidor sa programa FlameGraph gikan sa Brendan Gregg, nga nagpreserbar sa han-ay sa stack trace. Mahimo natong tipigan ang usa ka linya nga stack traces matag 1 ms, ug dayon i-highlight ug i-save ang sample 100 milliseconds sa dili pa moigo ang trace. 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

Ania ang mga resulta:

(сотни следов, которые выглядят похожими)

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

Adunay daghang mga butang dinhi, apan ang nag-unang butang mao nga atong makita ang "cadvisor before ksoftirqd" pattern nga atong nakita sa sayo pa sa ICMP tracer. Unsay buot ipasabot niini?

Ang matag linya usa ka pagsubay sa CPU sa usa ka punto sa oras. Ang matag tawag sa stack sa usa ka linya gibulag sa usa ka semicolon. Sa tunga-tunga sa mga linya atong makita ang syscall nga gitawag: read(): .... ;do_syscall_64;sys_read; .... Mao nga ang cadvisor naggugol ug daghang oras sa tawag sa sistema read()nga may kalabutan sa mga gimbuhaton mem_cgroup_* (ibabaw sa call stack/katapusan sa linya).

Dili kombenyente nga makita sa usa ka pagsubay sa tawag kung unsa gyud ang gibasa, busa padaganon ta strace ug tan-awon nato kung unsa ang gibuhat sa cadvisor ug pangitaon ang mga tawag sa sistema nga mas taas kaysa 100 ms:

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>

Sama sa imong gilauman, nakita namon ang hinay nga mga tawag dinhi read(). Gikan sa mga sulod sa pagbasa nga mga operasyon ug konteksto mem_cgroup klaro nga kini nga mga hagit read() refer sa file memory.stat, nga nagpakita sa paggamit sa memorya ug mga limitasyon sa cgroup (Docker's resource isolation technology). Ang himan sa cadvisor nangutana niini nga file aron makakuha og impormasyon sa paggamit sa kapanguhaan alang sa mga sudlanan. Atong susihon kung kini ba ang kernel o cadvisor nga nagbuhat usa ka butang nga wala damha:

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 ~ $

Karon mahimo na namon nga kopyahon ang bug ug masabtan nga ang kernel sa Linux nag-atubang sa usa ka patolohiya.

Nganong hinay kaayo ang read operation?

Niini nga yugto, mas dali nga makit-an ang mga mensahe gikan sa ubang mga tiggamit bahin sa parehas nga mga problema. Ingon nga kini nahimo, sa cadvisor tracker kini nga bug gitaho ingon problema sa sobra nga paggamit sa CPU, mao lang nga walay usa nga nakamatikod nga ang latency usab random nga gipakita sa network stack. Sa tinuud namatikdan nga ang cadvisor nag-usik og daghang oras sa CPU kaysa sa gipaabut, apan wala kini gihatagan ug importansya, tungod kay ang among mga server adunay daghang mga kapanguhaan sa CPU, mao nga ang problema wala gitun-an pag-ayo.

Ang problema mao nga ang mga cgroup nag-isip sa paggamit sa memorya sulod sa namespace (container). Kung ang tanan nga mga proseso sa kini nga cgroup exit, gibuhian ni Docker ang memory cgroup. Bisan pa, ang "memorya" dili lamang memorya sa proseso. Bisan tuod wala na gigamit ang memorya sa proseso mismo, makita nga ang kernel nag-assign gihapon sa mga cached nga sulod, sama sa mga dentries ug inodes (direktoryo ug file metadata), nga gi-cache sa memory cgroup. Gikan sa paghulagway sa problema:

zombie cgroups: cgroups nga walay mga proseso ug natangtang na, pero aduna gihapoy gigahin nga panumduman (sa akong kaso, gikan sa dentry cache, apan mahimo usab kini nga igahin gikan sa page cache o tmpfs).

Ang pagsusi sa kernel sa tanan nga mga panid sa cache sa diha nga ang pagpagawas sa usa ka cgroup mahimong hinay kaayo, mao nga ang tapolan nga proseso gipili: paghulat hangtud nga kini nga mga panid gihangyo pag-usab, ug unya sa katapusan paghawan ang cgroup sa diha nga ang memorya gikinahanglan gayud. Hangtud niini nga punto, ang cgroup gikonsiderar gihapon sa pagkolekta sa mga estadistika.

Gikan sa baroganan sa pasundayag, ilang gisakripisyo ang panumduman alang sa pasundayag: pagpadali sa inisyal nga pagpanglimpyo pinaagi sa pagbilin ug pipila ka naka-cache nga panumduman. Maayo kini. Sa diha nga ang kernel naggamit sa katapusan sa cached nga panumduman, ang cgroup sa katapusan ma-clear, mao nga dili kini matawag nga "leak". Ikasubo, ang piho nga pagpatuman sa mekanismo sa pagpangita memory.stat sa kini nga bersyon sa kernel (4.9), inubanan sa daghang memorya sa among mga server, nagpasabut nga mas dugay pa aron mapasig-uli ang labing bag-o nga na-cache nga datos ug ma-clear ang mga zombie sa cgroup.

Kini nahimo nga ang pipila sa among mga node adunay daghang mga cgroup nga zombie nga ang pagbasa ug latency milapas sa usa ka segundo.

Ang workaround alang sa problema sa cadvisor mao ang diha-diha dayon nga libre nga mga dentries/inodes caches sa tibuok sistema, nga diha-diha dayon nagwagtang sa read latency ingon man sa network latency sa host, tungod kay ang paglimpyo sa cache nagpalihok sa mga cached zombie cgroup nga mga panid ug nagpagawas usab kanila. Dili kini solusyon, apan kini nagpamatuod sa hinungdan sa problema.

Nahibal-an nga sa mas bag-ong mga bersyon sa kernel (4.19+) ang pasundayag sa pagtawag gipauswag memory.stat, mao nga ang pagbalhin sa kini nga kernel naayo ang problema. Sa parehas nga oras, kami adunay mga himan aron mahibal-an ang mga problema nga mga node sa mga pungpong sa Kubernetes, maayo nga habwaon kini ug i-reboot kini. Gisuklay namon ang tanan nga mga pungpong, nakit-an ang mga node nga adunay taas nga igo nga latency ug gi-reboot kini. Naghatag kini kanamo og panahon sa pag-update sa OS sa nahabilin nga mga server.

Sa pag-summarize

Tungod kay kini nga bug mihunong sa pagproseso sa RX NIC queue sulod sa gatusan ka milliseconds, kini dungan nga hinungdan sa taas nga latency sa mubo nga koneksyon ug tunga-tunga sa koneksyon latency, sama sa taliwala sa MySQL hangyo ug tubag packets.

Ang pagsabut ug pagmentinar sa pasundayag sa labing sukaranan nga mga sistema, sama sa Kubernetes, hinungdanon sa pagkakasaligan ug katulin sa tanan nga mga serbisyo base sa kanila. Ang matag sistema nga imong gipadagan makabenepisyo gikan sa mga pag-uswag sa performance sa Kubernetes.

Source: www.habr.com

Pag-debug sa latency sa network sa Kubernetes