De High Ceph Latency ĝis Kernel Patch uzante eBPF/BCC

De High Ceph Latency ĝis Kernel Patch uzante eBPF/BCC

Linukso havas grandan nombron da iloj por sencimigi la kernon kaj aplikaĵojn. Plej multaj el ili havas negativan efikon al aplikaĵo-agado kaj ne povas esti uzataj en produktado.

Antaŭ kelkaj jaroj ekzistis alia ilo estis evoluigita - eBPF. Ĝi ebligas spuri la kernon kaj uzantajn aplikaĵojn kun malalta superkosto kaj sen la bezono rekonstrui programojn kaj ŝargi triajn modulojn en la kernon.

Jam ekzistas multaj aplikaĵaj iloj, kiuj uzas eBPF, kaj en ĉi tiu artikolo ni rigardos kiel skribi vian propran profilan ilon bazitan sur la biblioteko. PythonBCC. La artikolo baziĝas sur realaj eventoj. Ni iros de problemo al riparo por montri kiel ekzistantaj utilecoj povas esti uzataj en specifaj situacioj.

Ceph Estas Malrapida

Nova gastiganto estis aldonita al la Ceph-areto. Migrinte iujn datumojn al ĝi, ni rimarkis, ke la rapideco de prilaborado de skribpetoj fare de ĝi estis multe pli malalta ol ĉe aliaj serviloj.

De High Ceph Latency ĝis Kernel Patch uzante eBPF/BCC
Male al aliaj platformoj, ĉi tiu gastiganto uzis bcache kaj la novan linuksan kernon 4.15. Ĉi tio estis la unua fojo, kiam gastiganto de ĉi tiu agordo estis uzata ĉi tie. Kaj en tiu momento estis klare, ke la radiko de la problemo teorie povus esti io ajn.

Esplorante la Gastiganton

Ni komencu rigardante kio okazas ene de la ceph-osd-procezo. Por tio ni uzos perfekta и flamskopo (pli pri kiuj vi povas legi tie):

De High Ceph Latency ĝis Kernel Patch uzante eBPF/BCC
La bildo diras al ni ke la funkcio fdatasync () pasigis multe da tempo sendante peton al funkcioj generic_make_request (). Ĉi tio signifas, ke plej verŝajne la kaŭzo de la problemoj estas ie ekster la osd-demono mem. Ĉi tio povas esti aŭ la kerno aŭ diskoj. La iostat-produktaĵo montris altan latentecon en prilaborado de petoj per bcache-diskoj.

Kontrolante la gastiganton, ni trovis, ke la systemd-udevd-demono konsumas grandan kvanton da CPU-tempo - ĉirkaŭ 20% sur pluraj kernoj. Ĉi tio estas stranga konduto, do vi devas ekscii kial. Ĉar Systemd-udevd funkcias kun ueventoj, ni decidis trarigardi ilin udevadm monitoro. Rezultas, ke granda nombro da ŝanĝaj eventoj estis generita por ĉiu bloka aparato en la sistemo. Ĉi tio estas sufiĉe nekutima, do ni devos rigardi kio generas ĉiujn ĉi tiujn eventojn.

Uzante la BCC Ilaron

Kiel ni jam eksciis, la kerno (kaj la ceph-demono en la sistemvoko) pasigas multe da tempo en generic_make_request (). Ni provu mezuri la rapidecon de ĉi tiu funkcio. EN BCC Jam ekzistas mirinda utileco - funkcioneco. Ni spuros la demonon per ĝia PID kun 1 sekunda intervalo inter eliroj kaj eligos la rezulton en milisekundoj.

De High Ceph Latency ĝis Kernel Patch uzante eBPF/BCC
Ĉi tiu funkcio kutime funkcias rapide. Ĉio, kion ĝi faras, estas transdoni la peton al la vico de la aparata ŝoforo.

Bcache estas kompleksa aparato kiu fakte konsistas el tri diskoj:

  • subtena aparato (kaŝmemordisko), ĉi-kaze ĝi estas malrapida HDD;
  • kaŝmemoriga aparato (kaŝmemordisko), ĉi tie ĉi estas unu sekcio de la NVMe-aparato;
  • la bcache virtuala aparato kun kiu la aplikaĵo funkcias.

Ni scias, ke tiu peto-transsendo estas malrapida, sed por kiu el ĉi tiuj aparatoj? Ni traktos ĉi tion iom poste.

Ni nun scias, ke eventoj verŝajne kaŭzos problemojn. Trovi kio ĝuste kaŭzas ilian generacion ne estas tiel facila. Ni supozu, ke ĉi tio estas ia programaro, kiu estas lanĉita periode. Ni vidu kian programaron funkcias en la sistemo per skripto execsnoop de la sama BCC ilaro. Ni rulu ĝin kaj sendu la eligon al dosiero.

Ekzemple tiel:

/usr/share/bcc/tools/execsnoop  | tee ./execdump

Ni ne montros la plenan eliron de execsnoop ĉi tie, sed unu linio de intereso por ni aspektis jene:

sh 1764905 5802 0 sudo arcconf getconfig 1 AD | grep Temperature | awk -F '[:/]' '{print $2}' | sed 's/^ ([0-9]*) C.*/1/'

La tria kolumno estas la PPID (gepatro PID) de la procezo. La procezo kun PID 5802 rezultis esti unu el la fadenoj de nia monitora sistemo. Kontrolinte la agordon de la monitora sistemo, estis trovitaj eraraj parametroj. La temperaturo de la HBA-adaptilo estis prenita ĉiujn 30 sekundojn, kio estas multe pli ofte ol necese. Ŝanĝinte la kontrolintervalon al pli longa, ni trovis, ke la peto prilaboranta latencia en ĉi tiu gastiganto ne plu elstaris kompare kun aliaj gastigantoj.

Sed ankoraŭ ne klaras, kial la bcache-aparato estis tiel malrapida. Ni preparis testan platformon kun identa agordo kaj provis reprodukti la problemon rulante fio sur bcache, periode kurante udevadm-eksilon por generi ueventojn.

Skribante BCC-bazitajn Ilojn

Ni provu skribi simplan ilon por spuri kaj montri la plej malrapidajn vokojn generic_make_request (). Ni ankaŭ interesiĝas pri la nomo de la stirado por kiu ĉi tiu funkcio estis nomita.

La plano estas simpla:

  • Registru ksondi sur generic_make_request ():
    • Ni konservas la disknomon en memoron, alirebla per la funkcio argumento;
    • Ni konservas la tempomarkon.

  • Registru kretprobe por reveno de generic_make_request ():
    • Ni ricevas la nunan tempomarkon;
    • Ni serĉas la konservitan tempomarkon kaj komparas ĝin kun la nuna;
    • Se la rezulto estas pli granda ol la specifita, tiam ni trovas la konservitan disknomon kaj montras ĝin sur la terminalo.

Ksondiloj и kretprobes uzu breakpoint mekanismon por ŝanĝi funkciokodon sur la flugo. Vi povas legi dokumentado и bona artikolo pri ĉi tiu temo. Se vi rigardas la kodon de diversaj utilecoj en BCC, tiam vi povas vidi, ke ili havas identan strukturon. Do en ĉi tiu artikolo ni transsaltos analizajn skriptoargumentojn kaj pluiros al la BPF-programo mem.

La eBPF-teksto ene de la python-skripto aspektas jene:

bpf_text = “”” # Here will be the bpf program code “””

Por interŝanĝi datumojn inter funkcioj, eBPF-programoj uzas hashtabloj. Ni faros same. Ni uzos la procezan PID kiel la ŝlosilon, kaj difinos la strukturon kiel la valoron:

struct data_t {
	u64 pid;
	u64 ts;
	char comm[TASK_COMM_LEN];
	u64 lat;
	char disk[DISK_NAME_LEN];
};

BPF_HASH(p, u64, struct data_t);
BPF_PERF_OUTPUT(events);

Ĉi tie ni registras hash-tabelon nomitan p, kun ŝlosiltipo u64 kaj valoro de tipo struct data_t. La tablo estos havebla en la kunteksto de nia BPF-programo. La makroo BPF_PERF_OUTPUT registras alian tabelon nomitan eventoj, kiu estas uzata por transdono de datumoj en uzantspacon.

Dum mezurado de prokrastoj inter vokado de funkcio kaj reveno de ĝi, aŭ inter vokoj al malsamaj funkcioj, vi devas konsideri, ke la ricevitaj datumoj devas aparteni al la sama kunteksto. Alivorte, vi devas memori pri la ebla paralela lanĉo de funkcioj. Ni havas la kapablon mezuri la latentecon inter vokado de funkcio en la kunteksto de unu procezo kaj reveno de tiu funkcio en la kunteksto de alia procezo, sed ĉi tio verŝajne estas senutila. Bona ekzemplo ĉi tie estus biolatenta utileco, kie la hashtabelŝlosilo estas agordita al montrilo al struct-peto, kiu reflektas unu diskpeton.

Poste, ni devas skribi la kodon, kiu ruliĝos kiam la studata funkcio estos nomita:

void start(struct pt_regs *ctx, struct bio *bio) {
	u64 pid = bpf_get_current_pid_tgid();
	struct data_t data = {};
	u64 ts = bpf_ktime_get_ns();
	data.pid = pid;
	data.ts = ts;
	bpf_probe_read_str(&data.disk, sizeof(data.disk), (void*)bio->bi_disk->disk_name);
	p.update(&pid, &data);
}

Ĉi tie la unua argumento de la nomita funkcio estos anstataŭigita kiel la dua argumento generic_make_request (). Post ĉi tio, ni ricevas la PID de la procezo en la kunteksto de kiu ni laboras, kaj la nuna tempomarko en nanosekundoj. Ni skribas ĉion en ĵus elektita struct data_t datumoj. Ni ricevas la disknomon de la strukturo naturema, kiu estas pasita dum vokado generic_make_request (), kaj konservu ĝin en la sama strukturo datumoj. La lasta paŝo estas aldoni eniron al la hashtabelo, kiu estis menciita antaŭe.

La sekva funkcio estos vokita ĉe reveno de generic_make_request ():

void stop(struct pt_regs *ctx) {
    u64 pid = bpf_get_current_pid_tgid();
    u64 ts = bpf_ktime_get_ns();
    struct data_t* data = p.lookup(&pid);
    if (data != 0 && data->ts > 0) {
        bpf_get_current_comm(&data->comm, sizeof(data->comm));
        data->lat = (ts - data->ts)/1000;
        if (data->lat > MIN_US) {
            FACTOR
            data->pid >>= 32;
            events.perf_submit(ctx, data, sizeof(struct data_t));
        }
        p.delete(&pid);
    }
}

Ĉi tiu funkcio estas simila al la antaŭa: ni ekscias la PID de la procezo kaj la tempomarkon, sed ne asignas memoron por la nova datumstrukturo. Anstataŭe, ni serĉas la hashtabelon por jam ekzistanta strukturo uzante la ŝlosilon == aktuala PID. Se la strukturo estas trovita, tiam ni ekscias la nomon de la funkcianta procezo kaj aldonas ĝin al ĝi.

La binara movo, kiun ni uzas ĉi tie, necesas por akiri la fadenon GID. tiuj. PID de la ĉefa procezo kiu komencis la fadenon en la kunteksto de kiu ni laboras. La funkcio, kiun ni nomas bpf_get_current_pid_tgid () resendas kaj la GID de la fadeno kaj ĝia PID en ununura 64-bita valoro.

Dum eligo al la terminalo, ni nuntempe ne interesiĝas pri la fadeno, sed ni interesiĝas pri la ĉefa procezo. Post kompari la rezultan prokraston kun donita sojlo, ni pasas nian strukturon datumoj en uzantspacon per tabelo eventoj, post kio ni forigas la eniron de p.

En la python-skripto, kiu ŝarĝos ĉi tiun kodon, ni devas anstataŭigi MIN_US kaj FACTOR per la prokrastaj sojloj kaj tempounuoj, kiujn ni trapasos la argumentojn:

bpf_text = bpf_text.replace('MIN_US',str(min_usec))
if args.milliseconds:
	bpf_text = bpf_text.replace('FACTOR','data->lat /= 1000;')
	label = "msec"
else:
	bpf_text = bpf_text.replace('FACTOR','')
	label = "usec"

Nun ni devas prepari la BPF-programon per BPF makroo kaj registri specimenojn:

b = BPF(text=bpf_text)
b.attach_kprobe(event="generic_make_request",fn_name="start")
b.attach_kretprobe(event="generic_make_request",fn_name="stop")

Ni ankaŭ devos determini struct data_t en nia skripto, alie ni nenion povos legi:

TASK_COMM_LEN = 16	# linux/sched.h
DISK_NAME_LEN = 32	# linux/genhd.h
class Data(ct.Structure):
	_fields_ = [("pid", ct.c_ulonglong),
            	("ts", ct.c_ulonglong),
            	("comm", ct.c_char * TASK_COMM_LEN),
            	("lat", ct.c_ulonglong),
            	("disk",ct.c_char * DISK_NAME_LEN)]

La lasta paŝo estas eligi datumojn al la terminalo:

def print_event(cpu, data, size):
    global start
    event = ct.cast(data, ct.POINTER(Data)).contents
    if start == 0:
        start = event.ts
    time_s = (float(event.ts - start)) / 1000000000
    print("%-18.9f %-16s %-6d   %-1s %s   %s" % (time_s, event.comm, event.pid, event.lat, label, event.disk))

b["events"].open_perf_buffer(print_event)
# format output
start = 0
while 1:
    try:
        b.perf_buffer_poll()
    except KeyboardInterrupt:
        exit()

La skripto mem haveblas ĉe GItHub. Ni provu ruli ĝin sur testa platformo kie fio funkcias, skribante al bcache, kaj voku udevadm monitor:

De High Ceph Latency ĝis Kernel Patch uzante eBPF/BCC
Fine! Nun ni vidas, ke tio, kio aspektis kiel ĉesiga bcache-aparato, estas efektive ĉesiga voko generic_make_request () por kaŝmemordisko.

Fosu en la Kernon

Kio precize malrapidiĝas dum petotranssendo? Ni vidas, ke la prokrasto okazas eĉ antaŭ la komenco de peta kontado, t.e. kontado de specifa peto pri plua eligo de statistiko pri ĝi (/proc/diskstats aŭ iostat) ankoraŭ ne komenciĝis. Ĉi tio povas esti facile kontrolita rulante iostat dum reproduktado de la problemo, aŭ BCC-skripto-biolateco, kiu baziĝas sur la komenco kaj fino de peta kontado. Neniu el ĉi tiuj iloj montros problemojn por petoj al la kaŝmemordisko.

Se ni rigardas la funkcion generic_make_request (), tiam ni vidos, ke antaŭ ol la peto komencas kontadon, du pliaj funkcioj estas nomitaj. Unue - generic_make_request_checks (), faras kontrolojn pri la legitimeco de la peto koncerne la diskajn agordojn. Due - blk_queue_enter(), kiu havas interesan defion atendo_evento_interrompebla():

ret = wait_event_interruptible(q->mq_freeze_wq,
	(atomic_read(&q->mq_freeze_depth) == 0 &&
	(preempt || !blk_queue_preempt_only(q))) ||
	blk_queue_dying(q));

En ĝi, la kerno atendas ke la vosto malfrosiĝos. Ni mezuru la prokraston blk_queue_enter():

~# /usr/share/bcc/tools/funclatency  blk_queue_enter -i 1 -m               	 
Tracing 1 functions for "blk_queue_enter"... Hit Ctrl-C to end.

 	msecs           	: count 	distribution
     	0 -> 1      	: 341  	|****************************************|

 	msecs           	: count 	distribution
     	0 -> 1      	: 316  	|****************************************|

 	msecs           	: count 	distribution
     	0 -> 1      	: 255  	|****************************************|
     	2 -> 3      	: 0    	|                                    	|
     	4 -> 7      	: 0    	|                                    	|
     	8 -> 15     	: 1    	|                                    	|

Ŝajnas, ke ni estas proksimaj al solvo. La funkcioj uzataj por frosti/malfrostigi vicon estas blk_mq_freeze_queue и blk_mq_unfreeze_queue. Ili estas uzataj kiam necesas ŝanĝi la agordojn de la petovico, kiuj estas eble danĝeraj por petoj en ĉi tiu vico. Kiam oni vokas blk_mq_freeze_queue() funkcio blk_freeze_queue_start () la nombrilo estas pliigita q->mq_freeze_depth. Post tio, la kerno atendas ke la vosto malpleniĝos blk_mq_freeze_queue_wait ().

La tempo necesa por malbari ĉi tiun vicon estas ekvivalenta al disko latenteco ĉar la kerno atendas ke ĉiuj vicigitaj operacioj finiĝos. Post kiam la atendovico estas malplena, la agordaj ŝanĝoj estas aplikataj. Post kio ĝi estas vokita blk_mq_unfreeze_queue(), malpliigante la nombrilon frosti_profundo.

Nun ni scias sufiĉe por korekti la situacion. La udevadm ellasilkomando kaŭzas la agordojn por la bloka aparato esti aplikata. Ĉi tiuj agordoj estas priskribitaj en la udev-reguloj. Ni povas trovi kiuj agordoj frostigas la atendovicon provante ŝanĝi ilin per sysfs aŭ rigardante la kernan fontkodon. Ni ankaŭ povas provi la ilon BCC spuro, kiu eligos kernon kaj uzantspacan stakspurojn por ĉiu voko al la terminalo blk_freeze_queueekzemple:

~# /usr/share/bcc/tools/trace blk_freeze_queue -K -U
PID 	TID 	COMM        	FUNC        	 
3809642 3809642 systemd-udevd   blk_freeze_queue
    	blk_freeze_queue+0x1 [kernel]
    	elevator_switch+0x29 [kernel]
    	elv_iosched_store+0x197 [kernel]
    	queue_attr_store+0x5c [kernel]
    	sysfs_kf_write+0x3c [kernel]
    	kernfs_fop_write+0x125 [kernel]
    	__vfs_write+0x1b [kernel]
    	vfs_write+0xb8 [kernel]
    	sys_write+0x55 [kernel]
    	do_syscall_64+0x73 [kernel]
    	entry_SYSCALL_64_after_hwframe+0x3d [kernel]
    	__write_nocancel+0x7 [libc-2.23.so]
    	[unknown]

3809631 3809631 systemd-udevd   blk_freeze_queue
    	blk_freeze_queue+0x1 [kernel]
    	queue_requests_store+0xb6 [kernel]
    	queue_attr_store+0x5c [kernel]
    	sysfs_kf_write+0x3c [kernel]
    	kernfs_fop_write+0x125 [kernel]
    	__vfs_write+0x1b [kernel]
    	vfs_write+0xb8 [kernel]
    	sys_write+0x55 [kernel]
    	do_syscall_64+0x73 [kernel]
    	entry_SYSCALL_64_after_hwframe+0x3d [kernel]
    	__write_nocancel+0x7 [libc-2.23.so]
    	[unknown]

Udev-reguloj sufiĉe malofte ŝanĝiĝas kaj kutime tio okazas en kontrolita maniero. Do ni vidas, ke eĉ apliki la jam fiksitajn valorojn kaŭzas pikon en la malfruo en translokigo de la peto de la aplikaĵo al la disko. Kompreneble, generi udev-eventojn kiam ne estas ŝanĝoj en la disko-agordo (ekzemple, la aparato ne estas muntita/malkonektita) ne estas bona praktiko. Tamen ni povas helpi la kernon ne fari nenecesan laboron kaj frostigi la petovicon se ĝi ne estas necesa. Tri malgranda kompromiti korekti la situacion.

konkludo

eBPF estas tre fleksebla kaj potenca ilo. En la artikolo ni rigardis unu praktikan kazon kaj montris malgrandan parton de tio, kion oni povas fari. Se vi interesiĝas pri disvolvi BCC-servaĵojn, indas rigardi oficiala lernilo, kiu bone priskribas la bazojn.

Estas aliaj interesaj sencimigaj kaj profilaj iloj bazitaj sur eBPF. Unu el ili - bpftrace, kiu permesas vin verki potencajn unu-liniojn kaj malgrandajn programojn en la awk-simila lingvo. Alia - ebpf_exporter, permesas vin kolekti malaltnivelajn, alt-rezoluciajn metrikojn rekte en vian prometheus-servilon, kun la kapablo poste ricevi belajn bildigojn kaj eĉ atentigojn.

fonto: www.habr.com

Aldoni komenton