Linux ima veliko orodij za odpravljanje napak v jedru in aplikacijah. Večina jih negativno vpliva na delovanje aplikacije in jih ni mogoče uporabiti v proizvodnji.
Pred nekaj leti je bilo — eBPF. Omogoča sledenje jedru in uporabniškim aplikacijam z nizkimi stroški in brez potrebe po ponovni izdelavi programov in nalaganju modulov tretjih oseb v jedro.
Obstaja že veliko aplikacijskih pripomočkov, ki uporabljajo eBPF, in v tem članku si bomo ogledali, kako napisati lasten pripomoček za profiliranje na podlagi knjižnice . Članek temelji na resničnih dogodkih. Prešli bomo od težave do rešitve, da bi pokazali, kako je mogoče obstoječe pripomočke uporabiti v določenih situacijah.
Ceph je počasen
Nov gostitelj je bil dodan v gručo Ceph. Po selitvi nekaterih podatkov nanj smo opazili, da je bila hitrost obdelave zahtev za pisanje precej nižja kot na drugih strežnikih.
Za razliko od drugih platform je ta gostitelj uporabljal bcache in novo jedro linux 4.15. To je bilo prvič, da je bil tukaj uporabljen gostitelj te konfiguracije. In v tistem trenutku je bilo jasno, da je koren problema teoretično lahko karkoli.
Preiskovanje gostitelja
Začnimo z ogledom, kaj se dogaja znotraj procesa ceph-osd. Za to bomo uporabili и (več o tem si lahko preberete ):
Slika nam pove, da funkcija fdatasync() porabil veliko časa za pošiljanje zahteve funkcijam generic_make_request(). To pomeni, da je najverjetneje vzrok težav nekje zunaj samega demona osd. To je lahko jedro ali diski. Izhod iostat je pokazal visoko zakasnitev pri obdelavi zahtev na diskih bcache.
Pri preverjanju gostitelja smo ugotovili, da demon systemd-udevd porabi veliko CPE-časa - približno 20 % na več jedrih. To je čudno vedenje, zato morate ugotoviti, zakaj. Ker Systemd-udevd deluje z dogodki, smo se odločili, da jih preučimo udevadm monitor. Izkazalo se je, da je bilo za vsako blokovno napravo v sistemu ustvarjeno veliko število dogodkov sprememb. To je precej nenavadno, zato bomo morali pogledati, kaj generira vse te dogodke.
Uporaba orodja BCC Toolkit
Kot smo že ugotovili, jedro (in ceph daemon v sistemskem klicu) preživi veliko časa v generic_make_request(). Poskusimo izmeriti hitrost te funkcije. IN Že obstaja čudovit pripomoček - funklatentnost. Demonu bomo sledili po njegovem PID z 1-sekundnim intervalom med izhodi in izpisali rezultat v milisekundah.
Ta funkcija običajno deluje hitro. Vse, kar naredi, je, da posreduje zahtevo v čakalno vrsto gonilnika naprave.
Bcache je kompleksna naprava, ki je dejansko sestavljena iz treh diskov:
- podporna naprava (predpomnjeni disk), v tem primeru je to počasen HDD;
- caching device (caching disk), tukaj je to ena particija naprave NVMe;
- virtualna naprava bcache, s katero teče aplikacija.
Vemo, da je prenos zahtev počasen, toda za katero od teh naprav? S tem se bomo ukvarjali malo kasneje.
Zdaj vemo, da bodo dogodki verjetno povzročili težave. Ugotoviti, kaj točno povzroča njihovo generacijo, ni tako enostavno. Predpostavimo, da je to nekakšna programska oprema, ki se občasno zažene. Poglejmo, kakšna programska oprema se izvaja v sistemu s pomočjo skripta execsnoop iz istega . Zaženimo ga in pošljimo izhod v datoteko.
Na primer takole:
/usr/share/bcc/tools/execsnoop | tee ./execdump
Tukaj ne bomo prikazali celotnega rezultata execsnoop, vendar je ena vrstica, ki nas zanima, izgledala takole:
sh 1764905 5802 0 sudo arcconf getconfig 1 AD | grep Temperature | awk -F '[:/]' '{print $2}' | sed 's/^ ([0-9]*) C.*/1/'
Tretji stolpec je PPID (nadrejeni PID) procesa. Izkazalo se je, da je proces s PID 5802 ena od niti našega nadzornega sistema. Pri preverjanju konfiguracije nadzornega sistema so bili odkriti napačni parametri. Temperaturo adapterja HBA smo merili vsakih 30 sekund, kar je veliko pogosteje, kot je potrebno. Po spremembi intervala preverjanja v daljšega smo ugotovili, da zakasnitev obdelave zahtev na tem gostitelju ni več izstopala v primerjavi z drugimi gostitelji.
Še vedno pa ni jasno, zakaj je bila naprava bcache tako počasna. Pripravili smo testno platformo z enako konfiguracijo in poskusili ponoviti težavo z zagonom fio na bcache, občasnim zagonom udevadm sprožilca za ustvarjanje uevents.
Pisanje orodij, ki temeljijo na BCC
Poskusimo napisati preprost pripomoček za sledenje in prikaz najpočasnejših klicev generic_make_request(). Zanima nas tudi ime pogona, za katerega je bila ta funkcija poklicana.
Načrt je preprost:
- Registrirajte se kprobe o generic_make_request():
- Ime diska shranimo v pomnilnik, dostopen prek argumenta funkcije;
- Shranimo časovni žig.
- Registrirajte se kretprobe za vrnitev iz generic_make_request():
- Dobimo trenutni časovni žig;
- Poiščemo shranjeni časovni žig in ga primerjamo s trenutnim;
- Če je rezultat večji od navedenega, poiščemo ime shranjenega diska in ga prikažemo na terminalu.
Ksonde и kretprobes uporabite mehanizem prekinitvene točke za sprotno spreminjanje kode funkcije. Lahko bereš и članek na to temo. Če pogledate kodo različnih pripomočkov v , potem lahko vidite, da imata enako strukturo. Zato bomo v tem članku preskočili argumente skripta za razčlenjevanje in prešli na sam program BPF.
Besedilo eBPF znotraj skripta python izgleda takole:
bpf_text = “”” # Here will be the bpf program code “””
Za izmenjavo podatkov med funkcijami uporabljajo programi eBPF . Tudi mi bomo storili enako. Uporabili bomo PID procesa kot ključ in definirali strukturo kot vrednost:
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);
Tukaj registriramo zgoščeno tabelo, imenovano p, z vrsto ključa u64 in vrednost tipa struct data_t. Tabela bo na voljo v okviru našega programa BPF. Makro BPF_PERF_OUTPUT registrira drugo klicano tabelo dogodki, ki se uporablja za v uporabniški prostor.
Pri merjenju zamikov med klicem funkcije in vrnitvijo iz nje ali med klici različnih funkcij je treba upoštevati, da morajo prejeti podatki pripadati istemu kontekstu. Z drugimi besedami, spomniti se morate na možni vzporedni zagon funkcij. Imamo možnost izmeriti zakasnitev med klicem funkcije v kontekstu enega procesa in vračanjem iz te funkcije v kontekstu drugega procesa, vendar je to verjetno neuporabno. Dober primer tukaj bi bil , kjer je ključ razpršilne tabele nastavljen na kazalec na zahteva struct, ki odraža eno zahtevo za disk.
Nato moramo napisati kodo, ki se bo zagnala ob klicu preučevane funkcije:
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);
}
Tukaj bo prvi argument klicane funkcije nadomeščen kot drugi argument . Po tem dobimo PID procesa, v okviru katerega delamo, in trenutni časovni žig v nanosekundah. Vse to zapišemo v sveže izbrano struct data_t data. Ime diska dobimo iz strukture bio, ki se posreduje pri klicu generic_make_request()in ga shranite v isto strukturo datum. Zadnji korak je dodajanje vnosa v zgoščeno tabelo, ki je bila omenjena prej.
Naslednja funkcija bo poklicana ob vrnitvi iz 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);
}
}
Ta funkcija je podobna prejšnji: ugotovimo PID procesa in časovni žig, vendar ne dodelimo pomnilnika za novo strukturo podatkov. Namesto tega iščemo v zgoščevalni tabeli že obstoječo strukturo z uporabo ključa == trenutni PID. Če je struktura najdena, ugotovimo ime tekočega procesa in mu ga dodamo.
Binarni premik, ki ga uporabljamo tukaj, je potreben za pridobitev GID niti. tiste. PID glavnega procesa, ki je zagnal nit, v kontekstu katere delamo. Funkcija, ki jo pokličemo vrne GID in PID niti v eni sami 64-bitni vrednosti.
Pri izpisu na terminal nas trenutno ne zanima nit, zanima pa nas glavni proces. Po primerjavi dobljene zakasnitve z danim pragom posredujemo našo strukturo datum v uporabniški prostor preko tabele dogodki, nakar izbrišemo vnos iz p.
V skriptu python, ki bo naložil to kodo, moramo MIN_US in FACTOR nadomestiti s pragovi zakasnitve in časovnimi enotami, ki jih bomo posredovali skozi argumente:
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"
Zdaj moramo pripraviti program BPF prek in registrirajte vzorce:
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")
Določiti bomo morali tudi struct data_t v našem skriptu, sicer ne bomo mogli prebrati ničesar:
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)]
Zadnji korak je izpis podatkov na terminal:
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()
Sam scenarij je na voljo na . Poskusimo ga zagnati na testni platformi, kjer se izvaja fio, piše v bcache in kliče udevadm monitor:
Končno! Zdaj vidimo, da je tisto, kar je bilo videti kot zaustavitev naprave bcache, dejansko zaustavitev klica generic_make_request() za predpomnjeni disk.
Poglobite se v jedro
Kaj točno se upočasni med prenosom zahteve? Vidimo, da do zamika pride že pred začetkom obračuna zahtevkov, tj. upoštevanje posebne zahteve za nadaljnji izpis statistike o njej (/proc/diskstats ali iostat) se še ni začelo. To lahko enostavno preverite tako, da zaženete iostat med reprodukcijo težave ali , ki temelji na začetku in koncu obračunavanja zahtev. Noben od teh pripomočkov ne bo prikazal težav pri zahtevah do predpomnjenega diska.
Če pogledamo funkcijo generic_make_request(), potem bomo videli, da se pred začetkom obračunavanja zahteve kličeta še dve funkciji. prvi - generic_make_request_checks(), izvaja preverjanje upravičenosti zahteve glede nastavitev diska. drugi - , ki ima zanimiv izziv :
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));
V njem jedro čaka, da se čakalna vrsta odmrzne. Izmerimo zamudo 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 | |
Videti je, da smo blizu rešitve. Funkcije, ki se uporabljajo za zamrznitev/odmrznitev čakalne vrste, so и . Uporabljajo se, ko je treba spremeniti nastavitve čakalne vrste zahtev, ki so potencialno nevarne za zahteve v tej čakalni vrsti. Ob klicu blk_mq_freeze_queue() po funkciji števec se poveča q->mq_globina_zamrzovanja. Po tem jedro počaka, da se čakalna vrsta izprazni .
Čas, ki je potreben za čiščenje te čakalne vrste, je enakovreden zakasnitvi diska, saj jedro čaka, da se dokončajo vse operacije v čakalni vrsti. Ko je čakalna vrsta prazna, se uporabijo spremembe nastavitev. Po katerem se imenuje , zmanjšanje števca zamrznitev_globina.
Zdaj vemo dovolj, da popravimo situacijo. Sprožilni ukaz udevadm povzroči uporabo nastavitev za blokirno napravo. Te nastavitve so opisane v pravilih udev. Katere nastavitve zamrznejo čakalno vrsto, lahko ugotovimo tako, da jih poskušamo spremeniti prek sysfs ali tako, da pogledamo izvorno kodo jedra. Lahko poskusimo tudi s pripomočkom BCC , ki bo izpisal sledi sklada jedra in uporabniškega prostora za vsak klic terminalu blk_freeze_queue, na primer:
~# /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]
Pravila Udev se redko spreminjajo in običajno se to zgodi na nadzorovan način. Vidimo torej, da tudi uporaba že nastavljenih vrednosti povzroči skokovit zamik pri prenosu zahteve iz aplikacije na disk. Seveda generiranje dogodkov udev, ko ni sprememb v konfiguraciji diska (na primer, naprava ni nameščena/odklopljena), ni dobra praksa. Lahko pa pomagamo jedru, da ne opravlja nepotrebnega dela in zamrznemo čakalno vrsto zahtev, če to ni potrebno. popraviti situacijo.
zaključek
eBPF je zelo prilagodljivo in zmogljivo orodje. V članku smo si ogledali en praktičen primer in pokazali delček tega, kar je mogoče storiti. Če vas zanima razvoj pripomočkov BCC, je vredno ogleda , ki dobro opisuje osnove.
Obstajajo še druga zanimiva orodja za odpravljanje napak in profiliranje, ki temeljijo na eBPF. En od njih - , ki vam omogoča pisanje zmogljivih enovrstičnih in majhnih programov v jeziku, podobnem awk. drugi - , vam omogoča zbiranje meritev nizke ravni z visoko ločljivostjo neposredno v vaš strežnik prometheus, z možnostjo kasnejšega pridobivanja čudovitih vizualizacij in celo opozoril.
Vir: www.habr.com