Fujtajbl vespolek..dnes si povíme o logování v Linuxu a způsobech, jak díky němu odhalit příčiny mnoha běžných problémů..
Na příspěvku jsem si dal docela dost práce, ale pokud ho dočtete do konce, nebudete zklamáni, protože v samotném závěru se na vlastní oči přesvědčíte, že i vy se můžete dostat až přímo k srdci problému, protože abych demonstroval co jsem zde napsal, demaskoval jsem v rámci tohoto návodu a hledání v logách kernelový bug na svém ntb..
--------------------------------------------
Intro -- Úvod do Logů
--------------------------------------------
Co to je to Log? Log bohužel není dle rozšířené představy ono samotné hlášení, ale je to až výstup z programu (nebo fce), který tato hlášení zachytává a obvykle následně zapíše do souboru a uloží na místo k tomu určené. Nejrozšířenější logovací démon je syslogd/syslogd-ng // new generation //, který se specializuje na zachytávání hlášení kernelu a jeho modulů. Stejně tak i většina ostatních programů má určité logovací funkce, která zachytávají hlášení ze stdout (standartní výstup) a zapisují je do souboru na disk.. Log je tedy seznam interních hlášení programu o tom, co provádí a jeho případné upozornění na chyby a problémy za běhu..
Logy v Linuxu jde v zásadě rozdělit na 2 skupiny ::
1) Hlášení jádra: "ukecanost" kernelu jde změnit předáním parametru 'loglevel=n' při bootu systému. Místo 'n' se dává číslo v rozsahu 0-7, přičemž 0 je žádná hlášení a 7 je nejvyšší míra "ukecanosti". Defaultní hodnota je AFAIK 'loglevel=3' ..
Hlášení jádra při bootování obstarává log jménem 'dmesg' (/var/log/dmesg) .. Ostatní logování zajišťuje typicky syslog (/var/log/syslog, /var/log/messages, ..) .. Pokud by nám nestačila základní logovací schopnost kernelu, můžeme při jeho ruční kompilaci zaškrtnout položky "extra debugging symbols" v sekci "kernel hacking" a nebo většina distribucí nabízí předkompilované jádro s touto volbou, které obvykle bývá označeno linux-2.6.x-debug ..
2) Všechna ostatní hlášení zbývajících programů: obvykle se jedná o často konfigurovatelné funkce konkrétních programů, které z konvence zapisují hlášení o běhu do /var/log (aka Xorg.log, vsftpd.log aj), ale i různě jinam. Některé externí programy se přímo kompilují s podporou knihoven syslogu -- překvapivě to je <syslog.h>
Pokud tedy na našem běžícím systému identifikujeme nějaký problém, bývá užitečné zaslídit v logách, které by nám mohly napovědět a nebo rovnou pomoci diagnostikovat danou závadu. Tento článek budiž malý úvod i s příklady, jak vyhledávat v logách a jak diagnostikovat problémy.
Protože budeme pracovat s příkazovým interpretem, zopakujeme si
v první části základní příkazy, které pro vyhledávání použijeme..
V rámci těchto příkladů si zopakujeme některé základní a jednoduché regulární výrazy, shellové struktury a přesměrování, která se pokusím srozumitelně popsat.
Ve
druhé části se podíváme a popíšeme si možnosti při diagnostikování a řešení samotných problémů.
A nakonec ve
třetí části demaskujeme kernelový bug nejen v syslogu, ale navíc přímo ve zdrojácích kernelu..
--------------------------------------------
První část -- Syntax Reference
--------------------------------------------
$
man cat // příkaz cat je jeden z nejzákladnejších unixových příkazů a vypíše obsah souboru, ale umí i mnoho dalších věcí..
$
cat -n /etc/X11/xorg.conf // vypíše xorg.conf a očísluje řádky
$
cat /dev/cdrom &>image.iso // vytvoří z Vašeho cdčka image.iso
$
cat <<'EOF'>file.txt // editor pro drsňáky pomocí cat. Otevře soubor pro zápis a ukončí ho napsáním a odklepnutím 'EOF' (End-Of-File) .. hodí se například v případě, že potřebujeme 'ohackovat' modem od o2, na který se sice přes telnet přihlásíme, ale který z bezpečnostních důvodů neobsahuje žádné nástroje pro práci s textem..
$
man grep // filtr pro vyhledávání. Příkaz grep je jeden z nejmocnějších unixových příkazů. Pokud hledáme něco konkrétního v dlouhém textovém souboru, je nenahraditelný. Dáte-li mu parametr
"-E", bude fungovat jako 'egrep' (enhanced grep) a vstupní filtr bude automaticky považovat za
regulární výraz (dále jen 'RE' aka
'regular expression' -- viz níže) a ne jako prostý
'řetězec'..
Nuže do toho.. grep se typicky používá v souvislosti s 'přesměrováním' :
$
dmesg | grep 'error' // vypíše všechny řádky, na kterých je výraz "error" (pozor - case sensitive) z příkazu dmesg.
$
cat /var/log/syslog | grep -E 'error|Error|ERROR' // jako výše uvedený příklad, akorát zde jsem použil egrep a konstrukci OR (samotný grep OR neumí, a onen 'výraz' by považoval za prostý řetězec k vyhledání, takže parametr "-E" je zde nezbytný) pomoci znaku
"|", která nám zajistí výpis řádků s rozdílným zápisem výrazu "error" (aka "Error", "ERROR", etc..).
!! Pro pochopení a používání RE je nezbytné, abychom si zapamatovali význam znaků "|" a "\" (escapování -- viz. níže). Je to důležité proto, že složitější RE vypadá často dost nečitelně, ale navyknete-li Vaše oko automaticky participovat části výrazu oddělené |, čitelnost a srozumitelnost se náležitě zvýší. Stejně platí u escapování: \ vypadá často dost "matoucně", ale v 95% případů escapuje znak za ním, který je pak většinou důležitý..$
grep -Erv 'error' /var/log // parametr
'-r' způsobí, že prohledá složku /var/log rekurzivně,
'-E' už známe a v tomhle případě není třeba, protože nepředáváme RE, ale jednoduchý řetězec
"error" a nakonec parametr
'-v' způsobí, že naopak vyřadí všechny řádky obsahující tento výraz, takže vlastně toto byl příklad naprosto neužitečného vyhledávání, protože všechny řádky s výrazem
"error" jsou nám zapovězeny..
$
grep -Ev '^#|^;|^$' /etc/samba/smb.conf // podobný příklad jako výše. V tomto případě už používáme opravdové RE a volba '-E' je tedy nutná. Tento příkaz vypíše obsah souboru smb.conf a vyřadí z něj všechny komentáře a prázdné řádky (řádky začínající znaky "#" a ";") .. V této souvislosti si zapamatujeme dva metaznaky v regulárním výraze, a sice
"^" -- začátek řádku, a
"$" -- konec řádku. Takže například:
$
ls . | grep -E '\.sh$' // způsobí, že výstup z příkazu 'ls .' filtrujeme grepem a zajímají nás v tuto chvíli všechny položky končící
".sh" .. Všimněte si také, že máme použitu konstrukci
'\.', což znamená, že díky znaku
"\" jsme vyescapovali další metaznak v regulárních výrazech a sice
"." (escapovaním jsme ji nepoužili jako metaznak, ale jako klasický znak v řetězci), která znamená libovolný jeden znak. Takže teď je nám jasné, že pokud bychom chtěli najít v nějakém souboru řetězec
"..^$^..", budeme muset zadat následující výraz
'\.\.\^\$\^\.\.' aby se nám naše znaky interpretovaly jako znak v textu a ne jako metaznak RE. Takže..
$
prikaz | grep -Ev '^.$|^\.' // ..v tomto případě vyřadí grep z výstupu
prikazu všechny řádky na kterých je pouze jeden libovolny znak vč. mezery a dále všechny řádky začínající tečkou .. Dále si ukážeme, jak vyhledávat komplikovanější řetězec pomocí opakování žolíkového znaku tečky:
$
prikaz | grep -E 'ACPI.*(error|Error|ERROR)' // vyhledá všechny řádky na nichž je výraz 'ACPI' následovaný libovolným řetězcem a dále slovem "error", "Error" a nebo "ERROR" (např. řetězec
"ACPI is ERROR"). Všimněte si zde použití kulatých
() pro "vložený výraz" a dalšího metaznaku
"*", který znamená libovolné množství opakování předchozího znaku, takže například
'^.*$' je elementární příklad pro řádek s libovolným obsahem, takže
$
'^a*x.*\.mp3$' je výraz pro vše co začíná "a" a jako další znak je neomezený počet dalších "a", následovaný jedním "x" a dalšími libovolnými znaky a končící ".mp3" (např.
"aaxyz.mp3", ale už ne
"aabxyz.mp3").. Je jasné, že chceme-li vyhledat výraz
"*.mp3", musíme použít
'\*\.mp3'..
!! Při použití * musíme výraz omezit jako '^vyraz*$' (začátek a konec řádku)
Nyní v rychlosti předvedu ještě jednu konstrukci pomocí
"[]" na výše uvedených příkladech..
$
prikaz | grep -E '^[0-9]{2,3}\.' // vyhledá ve výstupu příkazu všechny řádky začínající na 2-3 znaky dlouhý řetězec čísel následovaný tečkou -- takže např. začátek ip adresy .. tyto závorky [] se používají k přesnému vymezení znaku, a buď se do nich dá rozsah ala:
'[0-9]'" jako všecha čísla,
'[a-n]' jako písmena v lowercasu v rozsahu a-n,
'[a-zA-Z]' jako rozsah pro celou abecedu bez národních znaků jak kapitálkama, tak malým písmem,
'[#;@]' jako skupina znaku "#", ";" a "@" (takže výše uvedený příklad na vyřazení komentářů ze smb.conf jde udělat i takto
grep -Ev '^[#;]')..
$
prikaz | grep -A2 -B2 'prdlajz' // oddychový příklad na závěr, kdy grep navíc vypíše po dvou řádcích před (-B // aka before) a po (-A // aka after) kontextu "prdlajz" ..
$
man tail // zobrazí jenom konec souboru, defaultně 10 řádků
$
man head // zobrazí začátek souboru, o5 defaultně 10 řádků..
Když pro oba tyto příkazy použijeme přepínač "-n x", kde x je číslo, zobrazí se nám požadovaný počet řádků, takže:
$
dmesg | tail -n 25 // zobrazí posledních 25 řádků z dmesg
!! Cykly, které si předvedeme, rozhodně doporučuji vyzkoušet a pokusit se je pochopit. Cykly jako takové nebudu popisovat. Prostě je zkuste a pohrajte si s nima -- případně použijte google.
Nyní se podíváme na elementární použití a zápis cyklů na jeden řádek:$
for x in klaus topolanek paroubek bursik; do echo "$x"; done // základní zápis cyklu
for$
for x in $(ls ~); do echo "$x"; done // stejný zápis jako o řádek výše, akorát že jednotlivé elementy zde nemáme ručně, ale dostaneme je z příkazu 'ls ~' .. Cykly jdou samozřejmě kombinovat:
$
for x in $(ls /etc); do if [ ! -d "/etc/$x" ]; then echo "$x"; fi; done // zde to po rozboru na řádky vypadá takto:
// for x in $(ls /etc); do // "pro proměnou x obsahující výstup jednoho řádku při provádění 'ls /etc'
// if [ ! -d "/etc/$x" ]; then // "ověř, není-li řádek adresář. Pokud je, podmínka se nesplní a následuje další kolo..
// echo "$x" // "..a není-li, tak nám vytiskni jeho jméno v aktuálním kole jako proměnnou "$x"..
// fi
// done
$
for ((x=1;x<10;x++)) { echo "$x"; } // C-like syntaxe pri dalším typickém nasazení for..
$
echo $PATH | awk -F: '{ for(x=1;x<NF+1;x++) { print $x; }}' // použití for s příkazem awk. Zde je použit přepínač "-F" (file separator) s hodnotou ":", který nám rozdělí $PATH na pole oddělená ":" a v každém průběhu cyklu vytiskne jedno pole. Za zmínku stojí proměnná "NF", což je interní proměnná příkazu awk (viz. 'man awk' a sekce built-in variables) a znamená "
Number of
Fields". Jedničku přičítáme abychom vytiskl i poslední člen, jinak bychom místo "<" (menší než) potřebovali "=<" (menší nebo rovno) ..
$
while :; do clear && cat /var/log/syslog | tail -n 20 && sleep 2; done // takže zde si vytvoříme cyklus while, který probíhá dokud ho ručně nestopneme a zobrazuje nám v realtimu nové zápisy v syslogu na posledních 20 řádcích s obnovením jednou za 2 sekundy .. Zde si všimněte mého zápisu
prikaz1 && prikaz2 && prikaz3 a vyzkousejte sami rozdil mezi:
$
sleep 100; echo "cucis, co.." // spusťte tento příkaz a hned ho stopněte pomocí Ctrl+c
$
sleep 100 && echo "no, a ted uz nemas ani nac.." // dtto
--------------------------------------------
Druhá část -- Slídění v logách
--------------------------------------------
Slabé chvilky systému se dělí na dvě kategorie :
a) na transparentní == kdy máme záznam ze situace jak systém a nebo jeho část selhala ..
b) a všechny ostatní == kdy kritická situace z nějakého důvodu zalogovaná není a nebo jsme ji ještě nenašli, a nemusí být tedy na první pohled patrné, o co přesně běží ..
Setkáme-li se s první kategorií, není co řešit. Obvykle proženeme googlem "ukořistěnou hlášku" (někteří se však neobtěžují a rovnou běží na zdejší fórum) a pak je jen otázka času, kdy se nám podaří daný problém opravit..
Na druhé kategorii je optimistické to, že je možnost, že se změní v první tím, že po nějaké době přijdeme na kámen úrazu a můžeme ji začít řešit výše zmíněným způsobem.
Takže setkáme-li se s problémem, provedeme kroky, jejichž výsledek by měl být následující:
1) Zjistit co se stalo, zajistit inkriminovanou hlášku a determinovat problémovou část..
2) Obstarat si reference k problému z netu, manuálu a nebo od třetí osoby -- a nebo jsme-li dobří, zajistit si reference sami.
3) Na základě získaných referencí problém odstranit -- je-li samozřejmě známo jak na to (HOWTO)..
1) Zamyslíme se
.. Je třeba určit základní kategorii problému -- ?kernel, ?konkrétní aplikace ?možná miskonfigurace. Máme-li štěstí a chybová hláška se nám ukáže sama a problémem je miskonfigurace (ať už po našem zásahu a nebo vinou distribučního nastavení balíku), lze to vyřešit. Nemáme-li štěstí a potkáme hlášku
"core dumped" a nebo
"buffer overflow", je chyba přímo v kódu programu a jedná se o Bug. Také se může stát, že nemáme z čeho soudit a v tom případě se vrhneme na prohledávání logů. Samozřejmě platí, že použijeme všech dostupných prostředků (nepomůžou-li logy, zeptáme se internetu)
1.1) padá-li nám konkrétní aplikace, spustíme jí z terminálu, kam aplikace rovnou vypisujou zprávy o svém chodu.
Jako první věc můžeme zkontrolovat manuálovou stránku, jestli program podporuje volbu "verbose" (zvýšení výřečnosti).
Obvykle to bývá parametr "-v" nebo "-V". V případě potřeby (nesmyslně dlouhého a nebo nepřehledného outputu)
můžeme použít program 'tee', který zdvojuje stdout a dovoluje nám ho duplikovat i do souboru:
$
man tee && firefox | tee firefox.log // vytvoří v aktuálním adresáři soubor firefox.log
$
man strace // mocnej diagnostickej příkaz. Nebudu ho tady nijak rozebírat, je to v manpage. Příklad:
$
strace -e trace=open firefox // vypíše všechny soubory, které firefox otevřel..
Samozřejmě zkontrolujeme, zda-li program má svůj Log a ten prohlédneme..
-- výsledek by měl být zajištěná hláška o chybě..
1.2) Padá-li nám kernel je situace horší. Můžeme v úvodu popsaným způsobem zvýšit při bootu jeho ukecanost.
Můžeme v případě potřeby použít -debug jádro. Každopádně v tomto případě slídíme klasickými metodami v logách.
Extrémně užitečné se zde jeví otevřít si realtimové sledování vybraného logu, např:
$
while :; do clear && cat /var/log/syslog | tail -n 20 && sleep 1; done-- výsledek by měl být zajištění chybové hlášky a determinování problémové části..
-- nepodaří-li se nám v rámci bodu 1 zjistit co se děje, máme smůlu ..
2) Máme-li log a nebo víme co se děje (např. já když zapojím sluchátka, tak mi stále hrajou i repráčky, takže u mě je problém očividný a log nepotřebuju), můžeme googlit, ptát se, otravovat na fórech.. je to na nás. V této fázi bychom měli umět problém reprodukovat.. Zde se také často stává, že se zaseknete, protože jako já se sluchátky zjistíte, že řešení problému je zatím neznámé a nebo nedostupné.
-- výsledkem by mělo být nalezení teoretického řešení problému a nebo jeho případného stavu, je-li to známý problém.
3) Zde se pouštíme do samotné opravy -- pánbůh nám pomáhej.
-- výsledek
v ideálním případě je, že to nakonec opravíme..
--------------------------------------------
Třetí část -- Konkrétní Příklad
--------------------------------------------
Doporučuji Vám se na tento příklad podívat, protože zde máte ukázku toho, jak najít problém přímo ve zdrojáku a v rámci Našeho příkladu zde demonstruju, jak se dostat k "neřešitelnému" problému přímo na kobylku ..
// ok, koukneme se, jestli systém neobsahuje nějaké bugy..
# grep -Er 'error|Error|ERROR|fail|Fail|FAIL' /var/log // výstup je příliš veliký, trocha ho omezíme, ale předtím zkusíme:
# find /var/log | less // koukneme se, co všechno je v adresáři s logy a potom:
# for x in $(find /var/log); do if [ ! "$(echo "$x" | grep -E '\.tgz$|\.bz2|\.tar$|YaST2')" ] && [ ! -d "$x" ]; then
grep -E 'error|Error|ERROR|fail|Fail|FAIL' $x; fi; done // trocha si ten příkaz rozeberem..
// for x in $(find /var/log); do // v každém průběhu cyklu budeme zacházet s jednou položkou z /var/log
// if [ ! "$(echo "$x" | grep -E '\.tgz$|\.bz2|\.tar$|YaST2')" && [ ! -d "$x" ]; then
// pokud položka neobsahuje (!) koncovku jako archiv (tgz, bz2, tar), nepatří YaSTU (jehož errory me nezajímají)
// a není to zároveň (&&) adresář, tak..
// grep -E 'error|Error|ERROR|fail|Fail|FAIL' $x;
// ..jí bezstarostně progrepujeme -- v každém průběhu cyklu jednu z 'find /var/log' - krom zahozených
// fi
// done
// bohužel output je u mě stále příliš obrovský, takže já se jdu soustředit na užší vymezení 'error|Error|ERROR|fail|Fail|FAIL',
// budu slídit po 'ACPI' errors:
# for x in $(find /var/log); do if [ ! "$(echo "$x" | grep -E '\.tgz$|\.bz2|\.tar$|YaST2')" ] && [ ! -d "$x" ]; then
grep -E 'error|Error|ERROR|fail|Fail|FAIL' $x; fi; done | grep 'ACPI' // pripsal jsem to na konec..
// teď je to docela dobré.. mám asi 100 řádek díky výrazu 'ACPI|(error|Error|ERROR|fail|Fail|FAIL)' ..
// ok, vybírám si tuto hlášku:
// 'ACPI Error (psargs-0355): [BSTR] Namespace lookup failure, AE_NOT_FOUND'
// v google vyhledávám 'psargs-0355 Namespace lookup failure, AE_NOT_FOUND'
// nacházím spousta věcí, ale budu si hrát na moulu, páč do toho nevidím a zjistím si, co to přesně způsobuje:
# cd /usr/src/linux // vlezu ke zdrojákům jádra
# find . | grep -E 'ACPI|acpi' // kouknu se, kde je acpi schované, nacházím ho v ./drivers/acpi a nebo ./include/acpi
// ok, a teď se podíváme po naší hlášce:
# grep -rE -A3 'Namespace\ lookup\ failure' drivers/acpi // dostávám:
drivers/acpi/namespace/nsutils.c: acpi_os_printf(" Namespace lookup failure, %s\n",
drivers/acpi/namespace/nsutils.c- acpi_format_exception(lookup_status));
// a tady máme naši hlášku:
// stačí jen zjistit jak "acpi_format_exception(lookup_status)" vrací "AE_NOT_FOUND"
# grep -rE 'return\ .*AE_NOT_FOUND' drivers/acpi
drivers/acpi/ec.c: return AE_NOT_FOUND;
drivers/acpi/osl.c: return AE_NOT_FOUND;
drivers/acpi/osl.c: return AE_NOT_FOUND;
drivers/acpi/namespace/nsobject.c: return (AE_NOT_FOUND);
drivers/acpi/namespace/nsobject.c: return (AE_NOT_FOUND);
// a jedna z výše uvedených fcí je ta naše.. Bohužel se mi do tohohle příspěvku už nic nevejde (je tu limit 20.000 znaků)
tak.. a kdybych rozuměl psaní driverů pro acpi, tak si to ohackuju sám!
takto se prosím reší problémy a vyhledává v logách pod Linuxem
enjoy by ntz
Téma: Vyhledávání v Logách a základní použití RE .. (Přečteno 69994 krát)