Jaderné noviny – 19. 4. 2012: Strukturované logování v Linuxu

7. 5. 2012 | Luboš Doležel | Jaderné noviny | 3434×

Aktuální verze jádra: 3.4-rc3. Citáty týdne: Thomas Gleixner, Linus Torvalds. Alokace neinicializovaných bloků v souborech. Za spolehlivější logování.

Obsah

• Aktuální verze jádra: 3.4-rc3
• Citáty týdne: Thomas Gleixner, Linus Torvalds
• Alokace neinicializovaných bloků v souborech
• Za spolehlivější logování

Aktuální verze jádra: 3.4-rc3

Aktuální verze jádra je 3.4-rc3 vydaná 15. dubna. Krátký přehled změn najdete v příloze, ale nemyslím si, že by tam bylo něco zajímavého. Jde hlavně o aktualizace ovladačů s trochou oprav v architekturách a síťování. Suma sumárum bylo od 3.4-rc2 začleněno 332 sad změn.

Stabilní aktualizace: verze 3.0.28, 3.2.15 a 3.3.2 vyšly 13. dubna; všechny obsahují dlouhý seznam důležitých oprav.

Citáty týdne: Thomas Gleixner, Linus Torvalds

Na druhou stranu jsem byl vystaven zdrojovému kódu jistých ovladačů s utajeným zdrojovým kódem. Kvůli tomu jsem začal věřit že důvodem, proč mnohdy nechtějí zveřejnit zdrojový kód ovladačů, je to, že jeho zveřejnění by u nepřipravených osob mohlo při pohledu vyvolat rakovinu očí a žaludeční vředy.

Takže tuto změnu zařazuji z důvodu ochrany zdraví.

-- Thomas Gleixner

Pokud se vyznáte ve fyzice, tak o vydání (a tagu s ním spojeným) uvažujte jako o „kolapsu vlnové funkce“. Do té doby okolní svět nezná stav vašeho stromu (ale mohou jej odhadovat na základě patchů, které viděli) – a poté je to „hotové“. Nemůžete do toho zasahovat. A co je ještě důležitější, ostatní lidé mohou stav vidět, mohou jej měřit a záviset na něm.

-- Linus Torvalds

Jsem naprosto zvrácená osobnost. A jsem také neuvěřitelně inteligentní a fotogenický...

Připraveni? Z následujícího *oslepnete* – budete oslněni čistou krásou a intelektem skrytým v této věci:

#define IS_DEFINED(x) (__stringify(CONFIG_##x)[0]=='1')

Tohle je naprosté umělecké dílo. Očekávám, že se se mnou každou chvíli spojí Guggenheim.

-- Linus Torvalds

Alokace neinicializovaných bloků v souborech

Systémové volání fallocate() lze použít ke zvětšení velikosti souboru, aniž by došlo k zapsání nových bloků. Jde o užitečný způsob, jak jádru dát najevo, že by měl na disku rozmístit bloky za sebou nebo že by se měl ujistit, že je před zahájením operace na disku dostatek místa. Souborové systémy implementující fallocate() upozorňují, že nové bloky nejsou ve skutečnosti zapsány; snaha o čtení těchto neinicializovaných bloků obvykle vrátí samé nuly. Kdyby tomu tak nebylo, bylo by tu riziko prozrazení informací v blocích, které byly nedávno uvolněny z jiných souborů.

Pro většinu uživatelů funguje fallocate() tak, jak má. Někdy ale daná aplikace provádí spoustu zápisů na náhodných místech v souboru. Zapsání malého kousku dat v neinicializovaném extentu může způsobit, že souborový systém musí inicializovat mnohem větší rozsah bloků, což práci zpomalí. Ale pokud aplikace ví, kam do souboru zapsala, a tudíž nebude z neinicializovaných částí souboru nikdy číst, nemá toto extra úsilí žádný význam.

Jaké zbrzdění taková inicializace způsobí? Zheng Liu nedávno implementoval nový příznak pro fallocate() (nazvaný FALLOC_FL_NO_HIDE_STALE), který označí nové bloky jako inicializované, i když ve skutečnosti nedošlo k jejich zápisu; tyto bloky budou obsahovat náhodná stará data. Benchmark s náhodnými zápisy trval 76 sekund na běžném jádře a 18 sekund při zapnutí tohoto příznaku. Není nutné dodávat, že jde o značné zvýšení výkonu; z tohoto důvodu Zheng navrhl, aby tento příznak byl začleněn do hlavní řady.

Tato funkce má zjevné bezpečnostní dopady; Zhengův patch se je snaží napravit přidáním přepínače v sysctl, který by funkci zapínal a standardně by byl vypnutý. Přesto se tento nápad Ricu Wheelerovi nelíbí; řekl na to, že To vypadá, že navrhujeme přidání velké bezpečnostní díry místo toho, abychom se problémům s výkonem postavili čelem. Ted Ts'o byl o něco přístupnější, zejména kdyby přístup k funkčnosti vyžadoval capability jako CAP_SYS_RAWIO. Všichni ale zdá se souhlasí, že by bylo dobré nejprve zjistit, proč je v této situaci výkon tak špatný a jestli se to dá náležitě opravit. Pokud by bylo možné problém s výkonem opravit bez nutnosti změn v aplikacích nebo bez možného prozrazování citlivých dat, bylo by to pro všechny nakonec lepší.

Za spolehlivější logování

Zprávy z jádra jsou vytvořeny lidmi, typicky za pomoci jedné z variant funkce printk(). Čím dál častěji jsou přitom tyto zprávy čteny stroji v podobě parserů logů, automatizovaných systémů pro správu a tak dále. Tyto stroje už nějakou dobu mají co dělat, aby lidem napsaným zprávám porozuměly, protože jsou mnohdy chaotické, scházejí v nich podstatné informace a mění se. Proto není překvapivé, že se někdo vytrvale snaží o to, aby zprávy byly více strukturované; o tomto se mluvilo i na nedávném Collaboration Summitu. Zatím ale všechny pokusy o zlepšení selhaly.

Stejný osud čeká asi i Lennarta Poetteringa a Kaye Sieverse, kteří své nápady představili na Kernel Summitu 2011, šlo zejména o koncept připojování 128bitového unikátního ID ke každé zprávě, což narazilo na opovržení snad od všech lidí. Lennart a Kay to ale nevzdali. Poslední verze jejich práce je k vidění v patchi pro strukturované printk().

Patch dělá několik nesouvisejících věcí – což na mailing listu vedlo ke stížnostem. První věcí je změna jaderného logu ze streamu na řadu záznamů. Každá zpráva je uložena do bufferu s hlavičkou, která obsahuje délku, sekvenční číslo, facility a prioritu. Ve výsledku, jak Kay tvrdí, to nevede k nárůstu spotřebované paměti, ale spíše k mírnému poklesu.

Interní formát na bázi záznamů má řadu předností. Pokud jsou zprávy vytvářeny rychleji, než je uživatelský prostor zvládá číst, je nutné přepsat ty nejstarší. Současná jádra jednoduše přepíší proud znaků, což vede až k useknutým zprávám v logu. Nová implementace zahazuje celé zprávy, takže proud není nikdy poškozen, ačkoliv nemusí být kompletní. Sekvenční čísla umožňují zahozené zprávy odhalit. Tento formát také zlepšuje práci s navazujícími řádky, i když to u takových řádků znamená povinné používání „priority“ KERN_CONT.

Druhou změnou je povolení přidání čísla facility a „slovníku“, který obsahuje dodatečné informace, o které se budou zajímat automatické parsery. Slovník obsahuje páry KLÍČ=hodnota oddělené mezerami; tyto páry budou například obsahovat označení zařízení a subsystému, aby bylo možné jednoznačně odlišit původ zprávy. Jaderný kód, který chce přiřadit číslo facility nebo slovník ke zprávě, může použít novou funkci printk_emit():

int printk_emit(int facility, int level, const char *dict, 
		size_t dictlen, const char *fmt, ...);

Z obyčejného printk() se stává volání printk_emit() s facility nula a nulovým dict.

Vytvoření slovníku v podobě řetězce už je na volajícím; není to něco, co by bylo pravděpodobně možné vídat v místech, kde se printk() volá. Jediným plnohodnotným uživatelem printk_emit() v patchi je dev_printk(), které vytváří slovník s položkami SUBSYSTEM a DEVICE. Pokud bude takový patch začleněn, dá se očekávat, že právě takto to bude vypadat i jinde; vytváření slovníků s dodatečnými informacemi se bude asi řešit v print funkcích daného subsystému.

Na závěr patch mění vzhled zpráv, jak se dostávají do uživatelského prostoru. Po stížnostech od Linuse se formát rozvinul do této podoby:

7,384,6193747;sr 1:0:0:0: Attached scsi CD-ROM sr0
     SUBSYSTEM=scsi
     DEVICE=+scsi:1:0:0:0

Pole oddělená čárkou na začátku textu jsou priorita (v tomto případě 7), sekvenční číslo (384) a systémový čas od bootu v mikrosekundách. Zbytek řádky představuje zpráva předaná do printk(). Pokud zpráva obsahuje slovník, tak je tento zobrazen na dalších řádkách; dle stylu definovaného v RFC 821 začínají navazující řádky mezerou. Výsledkem je něco, co snad bude dostatečně čitelné pro lidi i stroje.

Chování zařízení /dev/kmsg se také tak trochu mění. V současných jádrech je toto zařízení použitelné jen pro vkládání zpráv do jaderného streamu. Kayův patch jej mění na zařízení, které podporuje i read() a poll() s podporou vícero současných uživatelů. Pokud jsou zprávy přepsány dříve, než je konkrétní uživatel stihne přečíst, příští volání read() vrátí chybu EPIPE; opakované čtení bude pokračovat od další zachované zprávy. Toto zařízení se tedy stává zdrojem jaderných logových zpráv, se kterým je snadné pracovat a který spolehlivě doručuje zprávy a současně umožňuje, aby uživatel zjistil, že něco schází.

Vyjma drobných neshod kolem formátu logu byla reakce na patch veskrze pozitivní. Největší výjimkou byl asi Ingo Molnar, jehož návrh, že by se spíš měly použít sledovací body (tracepoints) a perf, se nesetkaly s podporou. Dokonce i Linusovi se to líbí, a to asi díky tomu, že už tam nejsou žádná 128bitová unikátní ID. Ale tak jako tak má robustnější buffer zpráv se sekvenčními čísly jednoznačné výhody; Linus navrhl, že kdyby byla tato část patche vyčleněna, zvážil by zařazení do vydání 3.4. To se asi v této fázi cyklu už nestane, ale nebylo by překvapením, kdyby se něco podařilo dát dohromady pro vývojový cyklus verze 3.5. Pokud k tomu dojde, Linuxu bude stále scházet pravé strukturované logování, ale budu mít něco, co je do struktury a spolehlivosti lepší než současný stav.

       

Komentáře

[Michal Kubeček]

Z toho Linusova mailu (a celého toho šíleného threadu) se mi spíš líbilo

If you think that "stable" means "bug free", you are fundamentally confused about software engineering.

If you think you can go back in time and "undo" things, you are even more fundamentally confused about reality.

[Bedňa]

Ja viem že som neznaboh, ale čo alebo kto je ten Guggenheim?

[chrono]

Guggenheim

[Bedňa]

Tak moderné umenie, to dáva zmysel. Dík.