В Linux Ir pieejams liels skaits rīku kodolu un lietojumprogrammu atkļūdošanai. Lielākā daļa no tiem negatīvi ietekmē lietojumprogrammu veiktspēju un tos nevar izmantot ražošanas vidē.
Pirms pāris gadiem bija - eBPF. Tas ļauj izsekot kodolam un lietotāja lietojumprogrammām ar zemām izmaksām un bez nepieciešamības pārbūvēt programmas un ielādēt kodolā trešo pušu moduļus.
Jau ir daudz lietojumprogrammu utilītu, kas izmanto eBPF, un šajā rakstā mēs apskatīsim, kā izveidot savu profilēšanas utilītu, pamatojoties uz bibliotēku. . Raksts ir balstīts uz patiesiem notikumiem. Mēs pāriesim no problēmas uz labojumu, lai parādītu, kā esošās utilītas var izmantot konkrētās situācijās.
Kefs ir lēns
Ceph klasterim ir pievienots jauns saimniekdators. Pēc dažu datu migrēšanas uz to mēs pamanījām, ka rakstīšanas pieprasījumu apstrādes ātrums ar to bija daudz mazāks nekā citos serveros.
Atšķirībā no citām platformām šis resursdators izmantoja bcache un jauno Linux 4.15 kodolu. Šī bija pirmā reize, kad šeit tika izmantots šīs konfigurācijas resursdators. Un tajā brīdī bija skaidrs, ka problēmas sakne teorētiski varētu būt jebkas.
Saimnieka izmeklēšana
Sāksim ar to, kas notiek ceph-osd procesā. Šim nolūkam mēs izmantosim и (vairāk par to varat lasīt ):
Attēls parāda, ka funkcija fdatasync() pavadīja daudz laika, nosūtot pieprasījumu funkcijām generic_make_request(). Tas nozīmē, ka, visticamāk, problēmu cēlonis ir kaut kur ārpus paša osd dēmona. Tas var būt kodols vai diski. Iostata izvade uzrādīja lielu latentumu, apstrādājot pieprasījumus ar bcache diskiem.
Pārbaudot resursdatoru, mēs atklājām, ka systemd-udevd dēmons patērē daudz CPU laika - aptuveni 20% no vairākiem kodoliem. Tā ir dīvaina uzvedība, tāpēc jums ir jānoskaidro, kāpēc. Tā kā Systemd-udevd darbojas ar notikumiem, mēs nolēmām tos apskatīt udevadm monitors. Izrādās, ka katrai sistēmas blokierīcei tika ģenerēts liels skaits izmaiņu notikumu. Tas ir diezgan neparasti, tāpēc mums būs jāskatās, kas rada visus šos notikumus.
Izmantojot BCC rīku komplektu
Kā mēs jau esam noskaidrojuši, kodols (un ceph dēmons sistēmas izsaukumā) pavada daudz laika generic_make_request(). Mēģināsim izmērīt šīs funkcijas ātrumu. IN Jau ir brīnišķīga lietderība - funkcionalitāte. Mēs izsekosim dēmonu pēc tā PID ar 1 sekundes intervālu starp izvadēm un izvadīsim rezultātu milisekundēs.
Šī funkcija parasti darbojas ātri. Viss, ko tas dara, ir nosūtīt pieprasījumu ierīces draivera rindai.
Bcache ir sarežģīta ierīce, kas faktiski sastāv no trim diskiem:
- atbalsta ierīce (kešatmiņā saglabāts disks), šajā gadījumā tas ir lēns HDD;
- kešatmiņas ierīce (kešatmiņas disks), šeit šis ir viens NVMe ierīces nodalījums;
- bcache virtuālā ierīce, ar kuru darbojas lietojumprogramma.
Mēs zinām, ka pieprasījumu pārraide ir lēna, bet kurai no šīm ierīcēm? Mēs ar to nodarbosimies nedaudz vēlāk.
Tagad mēs zinām, ka notikumi var radīt problēmas. Atrast, kas tieši izraisa viņu paaudzi, nav tik vienkārši. Pieņemsim, ka šī ir sava veida programmatūra, kas tiek palaista periodiski. Apskatīsim, kāda veida programmatūra darbojas sistēmā, izmantojot skriptu execsnoop no tā paša . Palaidīsim to un nosūtīsim izvadi uz failu.
Piemēram, šādi:
/usr/share/bcc/tools/execsnoop | tee ./execdump
Šeit mēs neparādīsim pilnu execsnoop izvadi, taču viena mūs interesējošā rinda izskatījās šādi:
sh 1764905 5802 0 sudo arcconf getconfig 1 AD | grep Temperature | awk -F '[:/]' '{print $2}' | sed 's/^ ([0-9]*) C.*/1/'
Trešā kolonna ir procesa PPID (parent PID). Process ar PID 5802 izrādījās viens no mūsu uzraudzības sistēmas pavedieniem. Pārbaudot monitoringa sistēmas konfigurāciju, tika konstatēti kļūdaini parametri. HBA adaptera temperatūra tika mērīta ik pēc 30 sekundēm, kas ir daudz biežāk nekā nepieciešams. Pēc pārbaudes intervāla nomaiņas uz garāku, mēs atklājām, ka pieprasījuma apstrādes latentums šajā resursdatorā vairs neizceļas salīdzinājumā ar citiem saimniekdatoriem.
Bet joprojām nav skaidrs, kāpēc bcache ierīce bija tik lēna. Mēs sagatavojām testa platformu ar identisku konfigurāciju un mēģinājām reproducēt problēmu, palaižot fio uz bcache, periodiski palaižot udevadm trigeri, lai ģenerētu uevents.
Uz BCC balstītu rīku rakstīšana
Mēģināsim uzrakstīt vienkāršu utilītu, lai izsekotu un parādītu lēnākos zvanus generic_make_request(). Mūs interesē arī tā diska nosaukums, kuram šī funkcija tika izsaukta.
Plāns ir vienkāršs:
- Reģistrēties kprobe par generic_make_request():
- Mēs saglabājam diska nosaukumu atmiņā, kas pieejams, izmantojot funkcijas argumentu;
- Mēs saglabājam laika zīmogu.
- Reģistrēties kretprobe par atgriešanos no generic_make_request():
- Mēs iegūstam pašreizējo laika zīmogu;
- Mēs meklējam saglabāto laikspiedolu un salīdzinām to ar pašreizējo;
- Ja rezultāts ir lielāks par norādīto, mēs atrodam saglabātā diska nosaukumu un parādām to terminālī.
Kprobes и kretzondes izmantojiet pārtraukuma punkta mehānismu, lai lidojuma laikā mainītu funkcijas kodu. Jūs varat lasīt и rakstu par šo tēmu. Ja paskatās uz dažādu utilītu kodu , tad var redzēt, ka tiem ir identiska struktūra. Tāpēc šajā rakstā mēs izlaidīsim skripta argumentu parsēšanu un pāriesim pie pašas BPF programmas.
eBPF teksts python skriptā izskatās šādi:
bpf_text = “”” # Here will be the bpf program code “””
Lai apmainītos ar datiem starp funkcijām, eBPF programmas izmanto . Mēs darīsim tāpat. Mēs izmantosim procesa PID kā atslēgu un definēsim struktūru kā vērtību:
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);
Šeit mēs reģistrējam hash tabulu ar nosaukumu p, ar atslēgas veidu u64 un tipa vērtību struct data_t. Tabula būs pieejama mūsu BPF programmas kontekstā. Makro BPF_PERF_OUTPUT reģistrē citu tabulu ar nosaukumu notikumi, kas tiek izmantots lietotāja telpā.
Mērot aizkavi starp funkcijas izsaukšanu un atgriešanos no tās vai starp dažādu funkciju izsaukumiem, jāņem vērā, ka saņemtajiem datiem ir jāpieder vienam un tam pašam kontekstam. Citiem vārdiem sakot, jums jāatceras par iespējamu funkciju paralēlu palaišanu. Mums ir iespēja izmērīt latentumu starp funkcijas izsaukšanu viena procesa kontekstā un atgriešanos no šīs funkcijas cita procesa kontekstā, taču tas, visticamāk, ir bezjēdzīgi. Šeit būtu labs piemērs , kur hash tabulas atslēga ir iestatīta kā rādītājs uz struktūras pieprasījums, kas atspoguļo vienu diska pieprasījumu.
Tālāk mums jāraksta kods, kas darbosies, kad tiks izsaukta pētāmā funkcija:
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);
}
Šeit pirmais izsauktās funkcijas arguments tiks aizstāts kā otrais arguments . Pēc tam mēs iegūstam procesa PID, kura kontekstā mēs strādājam, un pašreizējo laikspiedolu nanosekundēs. Mēs to visu pierakstām tikko izvēlētā veidā struct data_t dati. Mēs iegūstam diska nosaukumu no struktūras bio, kas tiek nodota zvanot generic_make_request()un saglabājiet to tādā pašā struktūrā dati. Pēdējais solis ir pievienot ierakstu jaucēj tabulai, kas tika minēts iepriekš.
Atgriežoties no, tiks izsaukta šāda funkcija 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);
}
}
Šī funkcija ir līdzīga iepriekšējai: mēs noskaidrojam procesa PID un laikspiedolu, bet nepiešķiram atmiņu jaunajai datu struktūrai. Tā vietā mēs meklējam jaucēj tabulā jau esošu struktūru, izmantojot atslēgu == pašreizējais PID. Ja struktūra ir atrasta, tad noskaidrojam palaišanas procesa nosaukumu un pievienojam tam.
Binārā maiņa, ko mēs šeit izmantojam, ir nepieciešama, lai iegūtu pavedienu GID. tie. Galvenā procesa PID, kas aizsāka pavedienu, kura kontekstā mēs strādājam. Funkcija, ko mēs izsaucam atgriež gan pavediena GID, gan tā PID vienā 64 bitu vērtībā.
Izvadot uz termināli, mūs šobrīd neinteresē pavediens, bet gan galvenais process. Salīdzinot iegūto aizkavi ar doto slieksni, mēs izturam savu struktūru dati lietotāja telpā, izmantojot tabulu notikumi, pēc kura mēs izdzēšam ierakstu no p.
Python skriptā, kas ielādēs šo kodu, mums jāaizstāj MIN_US un FACTOR ar aizkaves sliekšņiem un laika vienībām, kuras mēs nodosim, izmantojot argumentus:
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"
Tagad mums ir jāsagatavo BPF programma, izmantojot un reģistrēt paraugus:
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")
Mums arī būs jānosaka struct data_t mūsu skriptā, pretējā gadījumā mēs nevarēsim neko izlasīt:
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)]
Pēdējais solis ir datu izvadīšana terminālī:
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()
Pats skripts ir pieejams vietnē . Mēģināsim palaist to testa platformā, kurā darbojas fio, rakstot uz bcache un izsaucam udevadm monitoru:
Beidzot! Tagad mēs redzam, ka tas, kas izskatījās kā apstājusies bcache ierīce, patiesībā ir apstājies zvans generic_make_request() kešatmiņā saglabātam diskam.
Iedziļināties kodolā
Kas tieši palēninās pieprasījuma pārsūtīšanas laikā? Redzam, ka kavēšanās notiek pat pirms pieprasījuma uzskaites sākuma, t.i. vēl nav sākusies konkrēta pieprasījuma uzskaite tālākai statistikas izvadīšanai par to (/proc/diskstats vai iostat). To var viegli pārbaudīt, palaižot iostatu, vienlaikus atkārtojot problēmu, vai , kuras pamatā ir pieprasījuma uzskaites sākums un beigas. Neviena no šīm utilītprogrammām neuzrādīs problēmas saistībā ar pieprasījumiem kešatmiņā saglabātajam diskam.
Ja skatāmies uz funkciju generic_make_request(), tad redzēsim, ka pirms pieprasījuma uzskaites sākšanas tiek izsauktas vēl divas funkcijas. Pirmkārt - generic_make_request_checks(), veic diska iestatījumu pieprasījuma likumības pārbaudes. Otrais - , kam ir interesants izaicinājums :
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));
Tajā kodols gaida, līdz rinda tiek atsaldēta. Izmērīsim kavēšanos 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 | |
Šķiet, ka esam tuvu risinājumam. Rindas iesaldēšanai/atsaldēšanai izmantotās funkcijas ir и . Tos izmanto, ja nepieciešams mainīt pieprasījumu rindas iestatījumus, kas ir potenciāli bīstami pieprasījumiem šajā rindā. Zvanot blk_mq_freeze_queue() funkcija skaitītājs tiek palielināts q->mq_freeze_depth. Pēc tam kodols gaida, līdz rinda tiks iztukšota .
Laiks, kas nepieciešams šīs rindas notīrīšanai, ir līdzvērtīgs diska latentumam, jo kodols gaida, līdz tiks pabeigtas visas rindā esošās darbības. Kad rinda ir tukša, tiek piemērotas iestatījumu izmaiņas. Pēc kura to sauc , samazinot skaitītāju iesaldēšanas_dziļums.
Tagad mēs zinām pietiekami daudz, lai situāciju labotu. udevadm trigera komanda liek lietot blokierīces iestatījumus. Šie iestatījumi ir aprakstīti udev noteikumos. Mēs varam noskaidrot, kuri iestatījumi iesaldē rindu, mēģinot tos mainīt, izmantojot sysfs vai apskatot kodola avota kodu. Mēs varam arī izmēģināt BCC utilītu , kas izvadīs kodola un lietotāja telpas steka trases katram termināļa izsaukumam blk_freeze_queue, piemēram:
~# /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 noteikumi mainās diezgan reti, un parasti tas notiek kontrolētā veidā. Tātad mēs redzam, ka pat jau iestatīto vērtību piemērošana izraisa aizkavēšanos pieprasījuma pārsūtīšanā no lietojumprogrammas uz disku. Protams, udev notikumu ģenerēšana, kad diska konfigurācijā nav izmaiņu (piemēram, ierīce nav uzstādīta/atvienota), nav laba prakse. Taču mēs varam palīdzēt kodolam neveikt liekus darbus un iesaldēt pieprasījumu rindu, ja tas nav nepieciešams. labot situāciju.
Secinājumi
eBPF ir ļoti elastīgs un spēcīgs rīks. Rakstā apskatījām vienu praktisku gadījumu un nodemonstrējām nelielu daļu no tā, ko var darīt. Ja jūs interesē BCC utilītu izstrāde, ir vērts to apskatīt , kas labi apraksta pamatus.
Ir arī citi interesanti atkļūdošanas un profilēšanas rīki, kuru pamatā ir eBPF. Viens no viņiem - , kas ļauj rakstīt jaudīgus vienas līnijas un nelielas programmas awk līdzīgā valodā. Cits - , ļauj apkopot zema līmeņa augstas izšķirtspējas metriku tieši savā Prometheus serverī ar iespēju vēlāk iegūt skaistas vizualizācijas un pat brīdinājumus.
Avots: www.habr.com
