Linux het 'n groot aantal gereedskap om die kern en toepassings te ontfout. Die meeste daarvan het 'n negatiewe impak op toedieningsprestasie en kan nie in produksie gebruik word nie.
'n Paar jaar gelede was daar - eBPF. Dit maak dit moontlik om die kern- en gebruikerstoepassings met lae bokoste op te spoor en sonder dat dit nodig is om programme te herbou en derdeparty-modules in die kern te laai.
Daar is reeds baie toepassingshulpmiddels wat eBPF gebruik, en in hierdie artikel sal ons kyk hoe om jou eie profielhulpmiddel gebaseer op die biblioteek te skryf . Die artikel is gebaseer op werklike gebeure. Ons gaan van probleem tot oplossing om te wys hoe bestaande nutsprogramme in spesifieke situasies gebruik kan word.
Ceph is stadig
'n Nuwe gasheer is by die Ceph-groepering gevoeg. Nadat ons van die data daarheen migreer het, het ons opgemerk dat die spoed van verwerking van skryfversoeke daardeur baie laer was as op ander bedieners.
Anders as ander platforms, het hierdie gasheer bcache en die nuwe Linux 4.15-kern gebruik. Dit was die eerste keer dat 'n gasheer van hierdie konfigurasie hier gebruik is. En op daardie oomblik was dit duidelik dat die wortel van die probleem teoreties enigiets kan wees.
Ondersoek die gasheer
Kom ons begin deur te kyk na wat binne die ceph-osd-proses gebeur. Hiervoor sal ons gebruik и (meer waaroor jy kan lees ):
Die prentjie vertel ons dat die funksie fdatasync() het baie tyd spandeer om 'n versoek na funksies te stuur generiese_maak_versoek(). Dit beteken dat die oorsaak van die probleme heel waarskynlik iewers buite die osd daemon self is. Dit kan óf die kern óf skywe wees. Die iostat-uitset het 'n hoë vertraging in die verwerking van versoeke deur bcache-skywe getoon.
Toe ons die gasheer nagaan, het ons gevind dat die systemd-udevd-demon 'n groot hoeveelheid SVE-tyd verbruik - ongeveer 20% op verskeie kerne. Dit is vreemde gedrag, so jy moet uitvind hoekom. Aangesien Systemd-udevd met u-events werk, het ons besluit om daarna te kyk udevadm monitor. Dit blyk dat 'n groot aantal veranderingsgebeurtenisse vir elke bloktoestel in die stelsel gegenereer is. Dit is nogal ongewoon, so ons sal moet kyk na wat al hierdie gebeure genereer.
Gebruik die BCC Toolkit
Soos ons reeds uitgevind het, spandeer die kern (en die ceph-demoon in die stelseloproep) baie tyd in generiese_maak_versoek(). Kom ons probeer om die spoed van hierdie funksie te meet. IN Daar is reeds 'n wonderlike nut - funksionaliteit. Ons sal die daemon opspoor deur sy PID met 'n 1 sekonde interval tussen uitsette en die resultaat in millisekondes uitstuur.
Hierdie kenmerk werk gewoonlik vinnig. Al wat dit doen, is om die versoek na die toestelbestuurder-waglys deur te gee.
Bcache is 'n komplekse toestel wat eintlik uit drie skywe bestaan:
- rugsteuntoestel (gekasskyf), in hierdie geval is dit 'n stadige HDD;
- kastoestel (kasskyf), hier is dit een partisie van die NVMe-toestel;
- die bcache virtuele toestel waarmee die toepassing loop.
Ons weet dat versoekoordrag stadig is, maar vir watter van hierdie toestelle? Ons sal dit 'n bietjie later hanteer.
Ons weet nou dat u-events waarskynlik probleme sal veroorsaak. Om te vind wat presies hul generasie veroorsaak, is nie so maklik nie. Kom ons neem aan dat dit 'n soort sagteware is wat periodiek bekendgestel word. Kom ons kyk watter soort sagteware op die stelsel loop deur 'n skrip te gebruik execsnoop van dieselfde . Kom ons hardloop dit en stuur die uitvoer na 'n lêer.
Byvoorbeeld, soos volg:
/usr/share/bcc/tools/execsnoop | tee ./execdump
Ons sal nie die volle uitset van execsnoop hier wys nie, maar een lyn van belang vir ons het soos volg gelyk:
sh 1764905 5802 0 sudo arcconf getconfig 1 AD | grep Temperature | awk -F '[:/]' '{print $2}' | sed 's/^ ([0-9]*) C.*/1/'
Die derde kolom is die PPID (ouer PID) van die proses. Die proses met PID 5802 blyk een van die drade van ons moniteringstelsel te wees. By die nagaan van die konfigurasie van die moniteringstelsel, is foutiewe parameters gevind. Die temperatuur van die HBA-adapter is elke 30 sekondes geneem, wat baie meer gereeld is as wat nodig is. Nadat ons die kontrole-interval na 'n langer een verander het, het ons gevind dat die versoekverwerkingsvertraging op hierdie gasheer nie meer uitstaan in vergelyking met ander gashere nie.
Maar dit is steeds onduidelik hoekom die bcache-toestel so stadig was. Ons het 'n toetsplatform met 'n identiese konfigurasie voorberei en probeer om die probleem te reproduseer deur fio op bcache te laat loop, en gereeld udevadm-sneller te laat loop om u-gebeurtenisse te genereer.
Skryf van BCC-gebaseerde gereedskap
Kom ons probeer om 'n eenvoudige hulpmiddel te skryf om die stadigste oproepe op te spoor en te vertoon generiese_maak_versoek(). Ons stel ook belang in die naam van die aandrywer waarvoor hierdie funksie genoem is.
Die plan is eenvoudig:
- Registreer kprobe op generiese_maak_versoek():
- Ons stoor die skyfnaam in die geheue, toeganklik deur die funksie-argument;
- Ons stoor die tydstempel.
- Registreer kretprobe vir terugkeer van generiese_maak_versoek():
- Ons kry die huidige tydstempel;
- Ons soek die gestoorde tydstempel en vergelyk dit met die huidige een;
- As die resultaat groter is as die gespesifiseerde een, vind ons die gestoorde skyfnaam en vertoon dit op die terminale.
Kprobes и kretprobes gebruik 'n breekpuntmeganisme om funksiekode dadelik te verander. Jy kan lees и artikel oor hierdie onderwerp. As jy kyk na die kode van verskeie nutsprogramme in , dan kan jy sien dat hulle 'n identiese struktuur het. So in hierdie artikel sal ons die ontleding van script-argumente oorslaan en aangaan na die BPF-program self.
Die eBPF-teks binne die python-skrip lyk soos volg:
bpf_text = “”” # Here will be the bpf program code “””
Om data tussen funksies uit te ruil, gebruik eBPF-programme . Ons sal dieselfde doen. Ons sal die proses PID as die sleutel gebruik en die struktuur definieer as die waarde:
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);
Hier registreer ons 'n hash-tabel genaamd p, met sleuteltipe u64 en 'n waarde van tipe struktuur data_t. Die tabel sal beskikbaar wees in die konteks van ons BPF-program. Die BPF_PERF_OUTPUT makro registreer 'n ander tabel genoem gebeure, wat gebruik word vir in gebruikersruimte.
Wanneer jy vertragings meet tussen die oproep van 'n funksie en die terugkeer daarvan, of tussen oproepe na verskillende funksies, moet jy in ag neem dat die ontvangde data aan dieselfde konteks moet behoort. Met ander woorde, jy moet onthou oor die moontlike parallelle bekendstelling van funksies. Ons het die vermoë om die latensie te meet tussen die oproep van 'n funksie in die konteks van een proses en die terugkeer van daardie funksie in die konteks van 'n ander proses, maar dit is waarskynlik nutteloos. 'n Goeie voorbeeld hier sou wees , waar die hash-tabelsleutel op 'n wyser gestel is struk versoek, wat een skyfversoek weerspieël.
Vervolgens moet ons die kode skryf wat sal loop wanneer die funksie onder studie genoem word:
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);
}
Hier sal die eerste argument van die geroepe funksie as die tweede argument vervang word . Hierna kry ons die PID van die proses in die konteks waarmee ons werk, en die huidige tydstempel in nanosekondes. Ons skryf dit alles neer in 'n vars uitgesoekte struct data_t data. Ons kry die skyfnaam van die struktuur bio, wat deurgegee word wanneer gebel word generiese_maak_versoek(), en stoor dit in dieselfde struktuur data. Die laaste stap is om 'n inskrywing by die hash-tabel te voeg wat vroeër genoem is.
Die volgende funksie sal opgeroep word by terugkeer vanaf generiese_maak_versoek():
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);
}
}
Hierdie funksie is soortgelyk aan die vorige een: ons vind die PID van die proses en die tydstempel uit, maar ken nie geheue toe vir die nuwe datastruktuur nie. In plaas daarvan soek ons die hash-tabel vir 'n reeds bestaande struktuur deur die sleutel == huidige PID te gebruik. As die struktuur gevind word, vind ons die naam van die lopende proses uit en voeg dit daarby.
Die binêre verskuiwing wat ons hier gebruik is nodig om die draad GID te kry. dié. PID van die hoofproses wat die draad begin het in die konteks waarmee ons werk. Die funksie wat ons noem gee beide die draad se GID en sy PID terug in 'n enkele 64-bis waarde.
Wanneer ons na die terminale uitvoer, stel ons nie tans belang in die draad nie, maar ons is geïnteresseerd in die hoofproses. Nadat ons die gevolglike vertraging met 'n gegewe drempel vergelyk het, slaag ons ons struktuur data in gebruikersruimte via tabel gebeure, waarna ons die inskrywing uitvee van p.
In die python-skrip wat hierdie kode sal laai, moet ons MIN_US en FACTOR vervang met die vertragingsdrempels en tydeenhede, wat ons deur die argumente sal slaag:
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"
Nou moet ons die BPF-program voorberei via en registreer monsters:
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")
Ons sal ook moet bepaal struktuur data_t in ons draaiboek, anders sal ons niks kan lees nie:
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)]
Die laaste stap is om data na die terminale uit te voer:
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()
Die skrif self is beskikbaar by . Kom ons probeer om dit te laat loop op 'n toetsplatform waar fio loop, skryf na bcache, en bel udevadm monitor:
Uiteindelik! Nou sien ons dat wat soos 'n stalling bcache toestel gelyk het, eintlik 'n stalling call is generiese_maak_versoek() vir 'n kasskyf.
Grawe in die kern
Wat presies vertraag tydens versoekoordrag? Ons sien dat die vertraging plaasvind selfs voor die aanvang van versoekrekeningkunde, m.a.w. verantwoording van 'n spesifieke versoek vir verdere uitvoer van statistieke daaroor (/proc/diskstats of iostat) het nog nie begin nie. Dit kan maklik geverifieer word deur iostat uit te voer terwyl die probleem gereproduseer word, of , wat gebaseer is op die begin en einde van versoekrekeningkunde. Geen van hierdie nutsprogramme sal probleme vir versoeke na die kasskyf wys nie.
As ons na die funksie kyk generiese_maak_versoek(), dan sal ons sien dat voordat die versoekrekeningkunde begin, nog twee funksies opgeroep word. Eerstens - generic_make_request_checks(), voer kontrole uit oor die legitimiteit van die versoek met betrekking tot die skyf-instellings. Tweede - , wat 'n interessante uitdaging het :
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));
Daarin wag die kern vir die tou om te ontvries. Kom ons meet die vertraging 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 | |
Dit lyk of ons naby 'n oplossing is. Die funksies wat gebruik word om 'n tou te vries/ontvries, is и . Hulle word gebruik wanneer dit nodig is om die versoektou-instellings te verander, wat potensieel gevaarlik is vir versoeke in hierdie tou. Wanneer gebel word blk_mq_freeze_queue() funksie die teller word verhoog q->mq_freeze_depth. Hierna wag die kern vir die tou om leeg te maak .
Die tyd wat dit neem om hierdie tou uit te vee is gelykstaande aan skyfvertraging aangesien die kern wag vir alle tou-bewerkings om te voltooi. Sodra die tou leeg is, word die instellingsveranderinge toegepas. Waarna dit genoem word , verlaag die toonbank vries_diepte.
Nou weet ons genoeg om die situasie reg te stel. Die udevadm-snelleropdrag veroorsaak dat die instellings vir die bloktoestel toegepas word. Hierdie instellings word in die udev-reëls beskryf. Ons kan vind watter instellings die tou vries deur dit te probeer verander deur sysfs of deur na die kernbronkode te kyk. Ons kan ook die BCC-hulpmiddel probeer , wat kern- en gebruikersruimtestapelspore vir elke oproep na die terminaal sal uitvoer blk_freeze_queue, byvoorbeeld:
~# /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-reëls verander redelik selde en gewoonlik gebeur dit op 'n beheerde manier. Ons sien dus dat selfs die toepassing van die reeds gestelde waardes 'n toename in die vertraging in die oordrag van die versoek van die toepassing na die skyf veroorsaak. Natuurlik is dit nie 'n goeie praktyk om udev-gebeurtenisse te genereer wanneer daar geen veranderinge in die skyfkonfigurasie is nie (byvoorbeeld, die toestel is nie gemonteer/ontkoppel nie). Ons kan egter die kern help om nie onnodige werk te doen nie en die versoektou vries as dit nie nodig is nie. die situasie reg te stel.
Gevolgtrekking
eBPF is 'n baie buigsame en kragtige instrument. In die artikel het ons na een praktiese geval gekyk en 'n klein deel gedemonstreer van wat gedoen kan word. As jy belangstel om BCC-nutsprogramme te ontwikkel, is dit die moeite werd om na te kyk , wat die basiese beginsels goed beskryf.
Daar is ander interessante ontfoutings- en profielinstrumente gebaseer op eBPF. Een van hulle - , wat jou toelaat om kragtige one-liners en klein programme in die awk-agtige taal te skryf. Nog 'n - , laat jou toe om laevlak-, hoë-resolusie-metrieke direk in jou prometheus-bediener in te samel, met die vermoë om later pragtige visualiserings en selfs waarskuwings te kry.
Bron: will.com