Linuxissa on suuri määrä työkaluja ytimen ja sovellusten virheenkorjaukseen. Useimmat niistä vaikuttavat negatiivisesti sovelluksen suorituskykyyn, eikä niitä voida käyttää tuotannossa.
Pari vuotta sitten oli - eBPF. Se mahdollistaa ytimen ja käyttäjäsovellusten jäljittämisen pienellä lisäkululla ja ilman tarvetta rakentaa ohjelmia uudelleen ja ladata kolmannen osapuolen moduuleja ytimeen.
eBPF:ää käyttäviä apuohjelmia on jo monia, ja tässä artikkelissa tarkastellaan, kuinka voit kirjoittaa oman profilointiapuohjelman kirjaston perusteella. . Artikkeli perustuu tositapahtumiin. Siirrymme ongelmasta korjaukseen näyttääksemme, kuinka olemassa olevia apuohjelmia voidaan käyttää tietyissä tilanteissa.
Ceph on hidas
Ceph-klusteriin on lisätty uusi isäntä. Siirrettyään osan tiedoista siihen, huomasimme, että sen kirjoituspyyntöjen käsittelynopeus oli paljon pienempi kuin muilla palvelimilla.
Toisin kuin muut alustat, tämä isäntä käytti bcachea ja uutta linux 4.15 -ydintä. Tämä oli ensimmäinen kerta, kun tämän kokoonpanon isäntä käytettiin täällä. Ja sillä hetkellä oli selvää, että ongelman juuri voi olla teoriassa mikä tahansa.
Isännän tutkiminen
Aloitetaan katsomalla, mitä ceph-osd-prosessissa tapahtuu. Tätä varten käytämme и (josta voit lukea lisää ):
Kuva kertoo meille, että toiminto fdatasync() vietti paljon aikaa pyynnön lähettämiseen toiminnoille generic_make_request(). Tämä tarkoittaa, että todennäköisesti ongelmien syy on jossain itse osd-daemonin ulkopuolella. Tämä voi olla joko ydin tai levyt. Iostaatin lähtö osoitti suurta viivettä bcache-levyjen käsittelyssä.
Tarkistaessamme isäntää havaitsimme, että systemd-udevd-daemon kuluttaa paljon suoritinaikaa - noin 20% useista ytimistä. Tämä on outoa käytöstä, joten sinun on selvitettävä miksi. Koska Systemd-udevd toimii utapahtumien kanssa, päätimme tarkastella niitä läpi udevadm-näyttö. Osoittautuu, että jokaiselle järjestelmän lohkolaitteelle generoitiin suuri määrä muutostapahtumia. Tämä on melko epätavallista, joten meidän on tarkasteltava, mikä synnyttää kaikki nämä tapahtumat.
BCC-työkalupaketin käyttäminen
Kuten olemme jo havainneet, ydin (ja ceph-daemon järjestelmäkutsussa) viettää paljon aikaa generic_make_request(). Yritetään mitata tämän funktion nopeus. SISÄÄN Siellä on jo upea apuohjelma - funktionaalisuus. Seuraamme demonia sen PID:llä 1 sekunnin välein lähtöjen välillä ja tulostamme tuloksen millisekunteina.
Tämä ominaisuus toimii yleensä nopeasti. Se vain välittää pyynnön laiteohjainjonoon.
Bcache on monimutkainen laite, joka koostuu itse asiassa kolmesta levystä:
- taustalaite (välimuistilevy), tässä tapauksessa se on hidas kiintolevy;
- välimuistilaite (välimuistilevy), tässä tämä on yksi NVMe-laitteen osio;
- bcache-virtuaalilaite, jonka kanssa sovellus toimii.
Tiedämme, että pyyntöjen lähetys on hidasta, mutta mihin näistä laitteista? Käsittelemme tätä hieman myöhemmin.
Tiedämme nyt, että tapahtumat aiheuttavat todennäköisesti ongelmia. Ei ole niin helppoa löytää, mikä tarkalleen aiheuttaa heidän sukupolvensa. Oletetaan, että tämä on jonkinlainen ohjelmisto, joka käynnistetään säännöllisesti. Katsotaan, millainen ohjelmisto toimii järjestelmässä komentosarjan avulla execsnoop samasta . Suoritetaan se ja lähetetään tulos tiedostoon.
Esimerkiksi näin:
/usr/share/bcc/tools/execsnoop | tee ./execdump
Emme näytä tässä execsnoopin täydellistä tulosta, mutta yksi meitä kiinnostava rivi näytti tältä:
sh 1764905 5802 0 sudo arcconf getconfig 1 AD | grep Temperature | awk -F '[:/]' '{print $2}' | sed 's/^ ([0-9]*) C.*/1/'
Kolmas sarake on prosessin PPID (emo-PID). Prosessi PID 5802:lla osoittautui yhdeksi valvontajärjestelmämme säikeistä. Valvontajärjestelmän kokoonpanoa tarkistettaessa löytyi virheellisiä parametreja. HBA-sovittimen lämpötila mitattiin 30 sekunnin välein, mikä on paljon useammin kuin on tarpeen. Vaihdettuamme tarkistusvälin pidemmäksi havaitsimme, että tämän isäntäkoneen pyynnön käsittelyviive ei enää eronnut muista isännistä verrattuna.
Mutta on edelleen epäselvää, miksi bcache-laite oli niin hidas. Valmistelimme testialustan, jolla oli identtinen kokoonpano, ja yritimme toistaa ongelman suorittamalla fio:n bcachessa ja ajamalla säännöllisesti udevadm-triggeriä utapahtumien luomiseksi.
BCC-pohjaisten työkalujen kirjoittaminen
Yritetään kirjoittaa yksinkertainen apuohjelma hitaimpien puhelujen jäljittämiseksi ja näyttämiseksi generic_make_request(). Olemme myös kiinnostuneita sen aseman nimestä, jota varten tämä toiminto kutsuttiin.
Suunnitelma on yksinkertainen:
- Rekisteröidy kprobe päälle generic_make_request():
- Tallennamme levyn nimen muistiin, joka on käytettävissä funktion argumentin kautta;
- Tallennamme aikaleiman.
- Rekisteröidy kretprobe paluuta varten generic_make_request():
- Saamme nykyisen aikaleiman;
- Etsimme tallennettua aikaleimaa ja vertaamme sitä nykyiseen;
- Jos tulos on suurempi kuin määritetty, etsimme tallennetun levyn nimen ja näytämme sen terminaalissa.
Kprobes и kret-koettimet käytä keskeytyskohtamekanismia muuttaaksesi toimintokoodia lennossa. Osaat lukea и artikkeli tästä aiheesta. Jos katsot eri apuohjelmien koodia , niin näet, että niillä on identtinen rakenne. Joten tässä artikkelissa ohitamme komentosarjaargumenttien jäsentämisen ja siirrymme itse BPF-ohjelmaan.
Python-skriptin sisällä oleva eBPF-teksti näyttää tältä:
bpf_text = “”” # Here will be the bpf program code “””
Tietojen vaihtamiseen funktioiden välillä eBPF-ohjelmat käyttävät . Teemme samoin. Käytämme prosessin PID:tä avaimena ja määritämme rakenteen arvoksi:
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);
Täällä rekisteröimme hash-taulukon nimeltä p, avaintyypin kanssa u64 ja tyypin arvo struct data_t. Taulukko on saatavilla BPF-ohjelmamme yhteydessä. BPF_PERF_OUTPUT-makro rekisteröi toisen taulukon nimeltä Tapahtumat, jota käytetään käyttäjätilaan.
Kun mitataan viiveitä funktion kutsumisen ja siitä paluumatkan välillä tai eri funktioiden kutsujen välillä, on otettava huomioon, että vastaanotettujen tietojen tulee kuulua samaan kontekstiin. Toisin sanoen, sinun on muistettava toimintojen mahdollinen rinnakkaiskäynnistys. Meillä on kyky mitata viivettä funktion kutsumisen yhden prosessin yhteydessä ja siitä funktiosta palaamisen välillä toisen prosessin yhteydessä, mutta tämä on todennäköisesti hyödytöntä. Tässä olisi hyvä esimerkki , jossa hash-taulukon avain on asetettu osoittimeksi rakennepyyntö, joka heijastaa yhtä levypyyntöä.
Seuraavaksi meidän on kirjoitettava koodi, joka suoritetaan, kun tutkittavaa funktiota kutsutaan:
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);
}
Tässä kutsutun funktion ensimmäinen argumentti korvataan toiseksi argumentiksi . Tämän jälkeen saamme sen prosessin PID:n, jonka kontekstissa työskentelemme, ja nykyisen aikaleiman nanosekunteina. Kirjoitamme kaiken ylös juuri valittuun struct data_t data. Saamme levyn nimen rakenteesta bio, joka ohitetaan soitettaessa generic_make_request(), ja tallenna se samassa rakenteessa tiedot. Viimeinen vaihe on lisätä merkintä hash-taulukkoon, joka mainittiin aiemmin.
Seuraava toiminto kutsutaan paluupaikasta 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);
}
}
Tämä toiminto on samanlainen kuin edellinen: selvitämme prosessin PID:n ja aikaleiman, mutta emme varaa muistia uudelle tietorakenteelle. Sen sijaan haemme hajautustaulukosta jo olemassa olevaa rakennetta avaimella == nykyinen PID. Jos rakenne löytyy, selvitämme käynnissä olevan prosessin nimen ja lisäämme sen siihen.
Tässä käyttämämme binäärisiirto tarvitaan säiettä GID:n saamiseksi. nuo. Pääprosessin PID, joka aloitti säikeen, jonka yhteydessä työskentelemme. Kutsumamme toiminto palauttaa sekä säikeen GID:n että sen PID:n yhtenä 64-bittisenä arvona.
Kun tulostetaan terminaaliin, emme tällä hetkellä ole kiinnostuneita säikeestä, mutta olemme kiinnostuneita pääprosessista. Kun tuloksena olevaa viivettä on verrattu tiettyyn kynnykseen, ohitamme rakenteemme tiedot käyttäjätilaan taulukon kautta Tapahtumat, jonka jälkeen poistamme merkinnän kohteesta p.
Python-skriptissä, joka lataa tämän koodin, meidän on korvattava MIN_US ja FACTOR viivekynnyksillä ja aikayksiköillä, jotka käymme läpi argumenttien:
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"
Nyt meidän on valmisteltava BPF-ohjelma kautta ja rekisteröi näytteitä:
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")
Meidän on myös päätettävä struct data_t käsikirjoituksessamme, muuten emme voi lukea mitään:
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)]
Viimeinen vaihe on tietojen tulostaminen terminaaliin:
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()
Itse käsikirjoitus on saatavilla osoitteessa . Yritetään ajaa se testialustalla, jossa fio on käynnissä, kirjoittaa bcacheen ja kutsua udevadm monitoria:
vihdoinkin! Nyt näemme, että se, mikä näytti pysähtyneeltä bcache-laitteelta, on itse asiassa pysähtynyt puhelu generic_make_request() välimuistissa olevalle levylle.
Kaivaudu ytimeen
Mikä tarkalleen ottaen hidastuu pyynnön lähetyksen aikana? Näemme, että viivästys tapahtuu jo ennen pyyntölaskennan alkamista, ts. sitä koskevien tilastojen lisätuotannon (/proc/diskstats tai iostat) erityisen pyynnön käsittely ei ole vielä alkanut. Tämä voidaan helposti tarkistaa suorittamalla iostat ongelman toistamisen aikana tai , joka perustuu pyyntökirjanpidon alkuun ja loppuun. Mikään näistä apuohjelmista ei näytä ongelmia välimuistissa olevalle levylle lähetetyissä pyynnöissä.
Jos katsomme toimintoa generic_make_request(), niin näemme, että ennen kuin pyyntö alkaa laskea, kutsutaan vielä kaksi funktiota. Ensimmäinen - generic_make_request_checks(), tarkistaa levyasetuksia koskevan pyynnön laillisuuden. Toinen - , jolla on mielenkiintoinen haaste :
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));
Siinä ydin odottaa jonon purkamista. Mitataan viive 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 | |
Näyttää siltä, että olemme lähellä ratkaisua. Toiminnot, joita käytetään jonon pysäyttämiseen/purkamiseen и . Niitä käytetään, kun on tarpeen muuttaa pyyntöjonon asetuksia, jotka voivat olla vaarallisia tässä jonossa oleville pyynnöille. Kun soitat blk_mq_freeze_queue() toiminto laskuri kasvaa q->mq_jäätymissyvyys. Tämän jälkeen ydin odottaa jonon tyhjenemistä .
Tämän jonon tyhjentämiseen kuluva aika vastaa levyn viivettä, kun ydin odottaa kaikkien jonossa olevien toimintojen valmistumista. Kun jono on tyhjä, asetusten muutokset otetaan käyttöön. Sen jälkeen sitä kutsutaan , laskee laskuria jäätymissyvyys.
Nyt tiedämme tarpeeksi korjataksemme tilanteen. Udevadm-trigger-komento saa aikaan lohkolaitteen asetusten soveltamisen. Nämä asetukset on kuvattu udev-säännöissä. Voimme selvittää, mitkä asetukset jumittavat jonon, yrittämällä muuttaa niitä sysfs:n kautta tai katsomalla ytimen lähdekoodia. Voimme myös kokeilla BCC-apuohjelmaa , joka tulostaa ytimen ja käyttäjätilan pinojäljet jokaiselle päätelaitteen kutsulle blk_freeze_queue, esimerkiksi:
~# /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-säännöt muuttuvat melko harvoin ja yleensä tämä tapahtuu hallitusti. Joten näemme, että jopa jo asetettujen arvojen soveltaminen aiheuttaa piikkien pyynnön siirtämisessä sovelluksesta levylle. Tietenkään udev-tapahtumien luominen, kun levykokoonpanossa ei ole muutoksia (esimerkiksi laitetta ei ole asennettu/irrotettu), ei ole hyvä käytäntö. Voimme kuitenkin auttaa ydintä olemaan tekemässä turhaa työtä ja jäädyttää pyyntöjonon, jos se ei ole välttämätöntä. korjata tilanne.
Yhteenveto
eBPF on erittäin joustava ja tehokas työkalu. Artikkelissa tarkastelimme yhtä käytännön tapausta ja osoitimme pienen osan siitä, mitä voidaan tehdä. Jos olet kiinnostunut BCC-apuohjelmien kehittämisestä, kannattaa tutustua , joka kuvaa hyvin perusasiat.
On muitakin mielenkiintoisia eBPF:ään perustuvia virheenkorjaus- ja profilointityökaluja. Yksi heistä - , jonka avulla voit kirjoittaa tehokkaita yksilinjaisia ohjelmia ja pieniä ohjelmia awk-kaltaisella kielellä. Toinen - , voit kerätä matalan tason korkearesoluutioisia mittareita suoraan prometheus-palvelimellesi, jolloin voit myöhemmin saada kauniita visualisointeja ja jopa hälytyksiä.
Lähde: will.com