Virtlab:LoggingDebugging

Z VirtlabWiki

(Rozdíly mezi verzemi)
Přejít na: navigace, hledání
Verze z 20:31, 29. 7. 2007
Gry72 (Diskuse | příspěvky)

← Předchozí porovnání		 Aktuální verze
Jan644 (Diskuse | příspěvky)
(→Ohlasovani chyb e-mailem)
Řádka 1: Řádka 1:
-== Logování a debugging ==+= Logování a debugging =
-Pro odladění, sledování provozu a řešení incidentů celého distribuovaného systému virtuální laboratoře je nutný '''konzistentní''' systém '''ukládání informací o běhu na různých úrovních''', které bude možné snadno '''automaticky vyhodnocovat a informovat příslušné správce o kritických nebo nestandardních stavech'''. Informace o běhu všech komponent (serverů) lokality budou '''shromažďovány na [http://www.scrambler.net/syslog.htm Syslog] serveru dané lokality''', kde budou '''vyhodnocovány vhodnými skripty nebo prostředky syslog démona a podle nastavených pravidel případně přeposílány emailem na správné zodpovědné správce'''. Logovací soubory syslog serverů všech lokalit budou zpřístupněny správcům všech ostatních lokalit (patrně přes WWW). +Pro odladění, sledování provozu a řešení incidentů celého distribuovaného systému virtuální laboratoře je nutný '''konzistentní''' systém '''ukládání informací o běhu na různých úrovních''', které bude možné snadno '''automaticky vyhodnocovat a informovat příslušné správce o kritických nebo nestandardních stavech'''. Informace o běhu všech komponent (serverů) lokality budou '''shromažďovány na [http://www.scrambler.net/syslog.htm Syslog] serveru dané lokality''', kde budou '''vyhodnocovány vhodnými skripty nebo prostředky syslog démona či pomocí phpsyslogng a podle nastavených pravidel případně přeposílány emailem na správné zodpovědné správce'''. Logovací soubory/databáze syslog serverů všech lokalit budou zpřístupněny pro čtení správcům všech ostatních lokalit (patrně přes WWW).
Z důvodu snadné implementace návazných rozšiření bude použit Syslog Next Generation (Syslog-ng). Z důvodu snadné implementace návazných rozšiření bude použit Syslog Next Generation (Syslog-ng).
-Jednotlivé servery systému budou '''zasílat debug informace na syslog jednotně pomocí k tomu účelu vytvořené univerzální funkce''' (C), kterou budou formou knihovny '''přilinkovávat''' (PHP bude volat jako externí program nebo bude vytvořen ekvivalent v PHP). Funkce předá zprávu Syslog serveru lokality (démonu Syslog-ng) nebo volitelně do souboru secifikovaného parametrem příkazového řádku. '''Parametry příkazového řádku související s debuggingem budou pro všechny servery sjednoceny''' (přilinkováním k tomu účelu vytvořené parsovací funkce v C). V případě, že budou servery lokality distribuovány na více strojů, bude na každém z nich instalován '''proxy syslog démon''', který bude nastaven tak, aby zprávy pouze přeposílal na hlavní Syslog démon lokality.+Jednotlivé servery systému budou '''zasílat debug informace na syslog jednotně pomocí k tomu účelu vytvořené univerzální logovací funkce''' (C), kterou budou formou knihovny '''přilinkovávat''' (PHP bude volat jako externí program nebo bude vytvořen ekvivalent v PHP). Funkce zformátuje hlášení dohodnutým způsobem a předá jej Syslog serveru lokality (démonu Syslog-ng), s ohledem na případné parametry nastavení logovacího režimu na příkazovém řádku (resp. konfiguračního souboru v případě PHP).
-=== Knihovní funkce pro logování ===+'''Parametry příkazového řádku související s debuggingem budou pro všechny servery sjednoceny''' (přilinkováním k tomu účelu vytvořené '''parsovací inicializační funkce''' v C).
-Abychom dosáhli jednotné a pro programátory bezpracné nastavení úrovně logování u každého programu, vytvořili jsme několik pomocných funkcí v C, které se ke každému serveru přilinkují (stačí staticky, mají pár set bytes). Jedná se o inicializační funkci a funkci pro zalogování zprávy, viz dále.+V případě, že budou servery lokality distribuovány na více strojů, bude na každém z nich instalován '''proxy syslog démon''', který bude nastaven tak, aby zprávy pouze přeposílal na hlavní Syslog démon lokality.
-U PHP kódu předpokládáme nastavení úrovně debugování ve vhodném .php souboru, který se pomocí include připojuje ke všem .php souborům (soubor s konstantami, soubor s autentizací ?).+== Sledování distribuovaných transakcí ==
 +Abychom mohli v log souborech dostopovat sekvenci souvisejících záznamů o akcích, které se provedly jako důsledek nějakého jednoho požadavku iniciovaného uživatelem (nebo i systémem, typicky od časovače), '''budeme v protokolech všech serverů označovat požadavky i odpovědi tzv. identifikátorem transakce (XID)'''. Identifikátor transakce bude hodnota ve tvaru '''XID=value''' (nebo např. '''XID:value''' podle požadavků příslušného protokolu) umístěná mezi volitelnými parametry v hlavičce všech požadavků, resp. odpovědi na požadavky. Hodnotu identifikátoru transakce '''vymyslí jednoznačně iniciátor transakce''' (obvykle WWW aplikace) a ostatní servery ji budou pouze vracet v odpovědích, resp. kopírovat do požadavků, které vytvoří jako reakci na příchozí požadavek s daným XID. A samozřejmě také logovat do log souborů. XID bude řetězec, způsob vytváření bude sjednocen takto:
 +'''název_lokality.konstanta_facility.ResID.UserID.unix_timestamp.'''
 +Je-li akce inicována systémovou komponentou, např. od časovače, místo jména uživatele bude řetězec '''#SYS#'''.
 +Pokud ResID nebo UserID není znám, použije se řetězec '''RUnknowm''', resp. '''UUnknown'''.
-=== Pomocná debug hlášení pro základní ladění (tracing) ===+== Unifikované nastavení chování logování ==
-'''Do informací zasílaných na Syslog nebudeme míchat debug hlášení pro základní ladění''' (trasování kódu programu, typicky posílané pomocí printf na stdout během ladění). Aby program neobsahoval množství těchto zapomenutých ladících printf(), zavedeme konvenci, že '''veškerá takováto hlášení budou vypisovány výhradně funkcí DBGPRINTF'''. Tu dokážeme snadno ve zdrojových kódech na základě názvu jednak snadno najít a případě odstranit, ale hlavně '''povolit či zakázat její efekt''' tím, že ji (pomoci #define ve [https://vl-test.cs.vsb.cz/websvn/filedetails.php?repname=virtlab&path=%2FDISTR%2Fsrc%2Flogging%2Fvl-debug.h&rev=0&sc=0 vl-debug.h]) budeme definovat jako funkci printf nebo nullprintf s prázdným tělem '''podle toho, zda je před připojením souboru vl-debug.h definován symbol DEBUG''' (při ladění musí být, #define VDEBUG).+
- +
-=== Unifikované nastavení chování logování ===+
- +
-Úroveň debuggingu všechny serverů (mimo WWW aplikace - '''tam jak ?''') lze určit pomocí jednotného systému parametrů předávaných z příkazové řádky. Parametry jsou koncipovány tak, aby mohly být zpracovány společnou inicializační funkcí přilinkovávanou ke každému serveru a následně odstraněny, aby neposouvaly pořadí a neovlivńovaly počet základních parametrů očekávaných programem. Jména jednotných parametrů nastavujících úroveň debuggingu začínají vždy řetězcem '''-DBGLOG''' a mají tvar '''-DBGLOGxxx''', resp. '''-DBGLOGxxx=hodnota'''. Na jejich pořadí včetně případném promísení s "normálními" parametry programu nezáleži. Načtení a odstranění debug parametrů se provede pomocí inicializační funkce '''initLogging(facilityID,*argc,*argv[])''' ([https://vl-test.cs.vsb.cz/websvn/filedetails.php?repname=virtlab&path=%2FDISTR%2Fsrc%2Flogging%2Fvl-debug.c&rev=0&sc=0 vl-debug.c]), která volá vždy jako '''první příkaz v main()''', tj. ještě před pokusem o parsování parametrů příkazové řádky vlastního programu.+
 +Úroveň debuggingu všech serverů (mimo WWW aplikace - '''tam pomocí vhodného .inc souboru''') lze určit pomocí jednotného systému parametrů předávaných z příkazové řádky. Parametry jsou koncipovány tak, aby mohly být zpracovány společnou inicializační funkcí přilinkovávanou ke každému serveru a následně automaticky odstraněny, aby neposouvaly pořadí a neovlivńovaly počet základních parametrů očekávaných programem. Jména jednotných parametrů nastavujících úroveň debuggingu začínají vždy řetězcem '''-DBGLOG''' a mají tvar '''-DBGLOGxxx''', resp. '''-DBGLOGxxx=hodnota'''. Na jejich pořadí včetně případném promísení s "normálními" parametry programu nezáleži. Načtení a odstranění debug parametrů se provede pomocí inicializační funkce '''initLogging(argc*,argv,facilityID)''' ([https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/COMMON/src/vl-debug.c vl-debug.c]), která se volá vždy jako '''první příkaz v main()''', tj. ještě před pokusem o parsování parametrů příkazové řádky vlastního programu. FacilityID viz vldebug.h.
-XXX '''FacilityID''' se vezme ze souboru vl-debug.h a nastavi se pro cely beh programu, takze se bude pouzivat jako default ve volanich syslog(), kde uz staci uvadet jen prioritu. 
Momentálně jsou definovány tyto parametry: Momentálně jsou definovány tyto parametry:
-* -DBGLOG-LEVEL=x 
-* -DBGLOG-FILE=x - jméno souboru, kam se má logovat (default na lokální Syslogd) 
 +* -DBGLOGsite=x - nastaveni jmena mistni lokality (jen pro ucely logovani). Implicitne se bere s /etc/sitename.
 +* -DBGLOGlevel={EMERG|ALERT|CRIT|ERR|WARNING|NOTICE|INFO|DEBUG} - od kterého debug levelu se mají hlášení skutečně posílat na Syslog. Pokud není explicitně nastaveno, použije se '''LOG_CRIT'''.
-=== Ošetření neočekávaných chyb ===+Možná ješte doplníme -DBGLOG-actions=xxx blíže určující, jaké "typy" informací se maji ukladat v levelu debug (DB access, mezikomponentová komunikace, forking/exitting procesů, info o běhu algoritmů, ...) ???
- +
-Přiznejme si, že není možné ošetřit úplně všechno (i když se budeme snažit). Nicméně bychom měli aspoň vědět o tom, že vyvstal problém tam, kde jsme jej nečekali a kde přesně do bylo. Pokud tedy nějaká systémová funkce vrací chybový kód, který nechceme dále rozlišovat, protože jeho vrácení prostě nepředpokládáme, budeme volat '''před použitím jakéhokoli dalšího systémového volání''' (aby se nepřepsala hodnota proměnné errno) funkci '''LOG_UNEXPECTED_SYS_ERROR()''' (viz [https://vl-test.cs.vsb.cz/websvn/filedetails.php?repname=virtlab&path=%2FDISTR%2Fsrc%2Flogging%2Fvl-debug.c&rev=0&sc=0 vl-debug.c]), která zaloguje kód a vysvětlující text chyby ('''strerror(errno)''') spolu se jménem zdrojového kódu a číslem řádku, na kterém je volání LOG_UNEXPECTED_SYS_ERROR() umístěno. Obdobným způsobem ošetřujeme uživatelské funkce, které nenastavují errno, pouze s tím rozdílem, že použijeme funkci '''LOG_UNEXPECTED_USR_ERROR(errcode)''', jejímž parametrem je právě neočekávaný chybovž kód uživatelské funkce (tedy typický zápis bude '''LOG_UNEXPECTED_USR_ERROR(UserFunc(...));''' ). Pokud je errcode, resp. předaný parametr 0, obě funkce nedělají nic.+
- +
- +
-=== Formát logovacích zpráv ===+
- +
-Údaje, které potřebujeme ukládat:+
-* timestamp+
-* ID generující komponenty - facility+
-* Jméno lokality generující komponenty+
-* PID+
-* source file & line+
-* Partnerská lokalita - při komunikačních akcích, pro snadné GREPování chybových zpráv a zasílání informace správci přislušné lokality+
-* Vysvětlující text - jednořádkový, '''pro srozumitelnost potenciálním cizincům v angličtině''' +
- +
-Formát logovacích zpráv je částečně předurčen formátem používaných Syslogem. +
-'''Timestamp''' a '''IP adresu zdroje''' zprávy dodá Syslogd, '''PID''' dodá funkce syslog().+
- +
=== Úrovně logování === === Úrovně logování ===
-Úrovně logování (priority zpráv) částečně předurčeny formátem používaných Syslogem. +Úrovně logování (priority hlášení) jsou částečně předurčeny logikou zavedenou Syslogem:
* LOG_EMERG (system is unusable) * LOG_EMERG (system is unusable)
* LOG_ALERT (action must be taken immediately) * LOG_ALERT (action must be taken immediately)
* LOG_CRIT (critical conditions) * LOG_CRIT (critical conditions)
-* LOG_ERR (error conditions) - ignorované neočekávané chyby vrácené ze systémových. resp. uživatelských volání (neošetřené) - použití funkcí LOG_UNEXPECTED_SYS_ERROR, resp. LOG_UNEXPECTED_USR_ERROR.+* LOG_ERR (error conditions)
- +
-Text zprávy pak obsahuje jméno a řádek zdrojového kódu, kde chyba vznikla, a popisné hlášení chyby generované funkcí perror() na základě globální proměnné errno. Lze použít makro ; Pozor, nevolat mezitím jiné systémové volání, to by změnilo obsah errno.+
- +
* LOG_WARNING (warning conditions) * LOG_WARNING (warning conditions)
* LOG_NOTICE (normal, but significant, condition) * LOG_NOTICE (normal, but significant, condition)
Řádka 70: Řádka 48:
* LOG_DEBUG (debug-level message) * LOG_DEBUG (debug-level message)
-Z priorit Syslogu využíváme následující úrovně:+Z úrovní Syslogu využíváme následující úrovně:
-Používané facilities a synonyma použivaná pro jednotlivé facilities jsou v souboru vl-debug.h+* Aktuální zjednodušení v serverových komponentách v C++:
 +** CRIT - výpadek komponenty (vhodný k posílání SMS administrátorům)
 +** INFO - stručné informace o probíhajících zásadních akcích/událostech
 +** WARNING - zotavitelená chyba (důvod jejíhož by se nicméně měl analyzovat)
 +** DEBUG - detailní ladící informace o probíhajících akcích/událostech, včetně parametrů.
 + 
 + 
 +* Původní (příliš složitý) plán:
 +** LOG_DEBUG - info o akcích a interakcích komponent systému a stavech algoritmů - podrobné (doplňující LOG_INFO], vč. parametrů, dump zpráv vyměňovaných mezi komponenty, výpis přijatých a odeslaných dat, forking & exiting dynamicky vytvářených podprocesů, info o databázových operacích (texty prováděných SQL příkazů).
 +** LOG_INFO - info o zásadních akcích a interakcích komponent systému a stavech algoritmů (došlé požadavky a reakce na ně, výsledky výpočtů, spouštění akcí od časovače), - jednořádkové
 +** LOG_NOTICE - info o komunikačních akcích - přijatá a navázaná spojení + chyby,
 +** LOG_WARNING - info o chybách, ze kterých se systém zotavil
 +** LOG_ERR - ignorované neočekávané chyby vrácené ze systémových. resp. uživatelských volání (neošetřené)- Generují se použitím pomocně vytvořených funkcí '''LOG_UNEXPECTED_SYS_ERROR''', resp. '''LOG_UNEXPECTED_USR_ERROR(errcode)'''. Text vygenerované zprávy pak bude obsahovat jméno a řádek zdrojového kódu, kde chyba vznikla, u funkce '''LOG_UNEXPECTED_SYS_ERROR''' popisné hlášení chyby generované funkcí perror() na základě globální proměnné errno a u funkce '''LOG_UNEXPECTED_USR_ERROR''' číslo chyby předané jako argument. Mezi voláním ošetřované funkce a voláním '''LOG_UNEXPECTED_SYS_ERROR''' nesmí být volána jiná systémová volání, která by změnila obsah errno.
 +** LOG_CRIT (critical conditions) - informace o výpadku některých komponent vyžadující okamžitý administrátorský zásah (výpadek části systému). Taktéž problémy se startem komponent způsobené špatnou konfigurací.
 +** LOG_ALERT - informace o stavech způsobených chybou v kódu vyžadující odstranění chyby přeprogramováním
 + 
 + 
 +Facilities určují v Syslogu zdroj, resp. v našem případě komponentu, která vygenerovala hlášení.
 +Používané (číselné) identifikátory facilities a synonyma použivaná pro jednotlivé facilities jsou v souboru '''vl-debug.h''':
*FAC_WWWAPP (LOG_LOCAL0) - webová aplikace řídícího serveru lokality (GUI, mapovací algoritmus) *FAC_WWWAPP (LOG_LOCAL0) - webová aplikace řídícího serveru lokality (GUI, mapovací algoritmus)
Řádka 79: Řádka 75:
*FAC_CONSSRV (LOG_LOCAL0+2) - konzolový server *FAC_CONSSRV (LOG_LOCAL0+2) - konzolový server
*FAC_CONFSRV (LOG_LOCAL0+3) - konfigurační server *FAC_CONFSRV (LOG_LOCAL0+3) - konfigurační server
-*FAC_CONFACT (LOG_LOCAL0+4) - aktivátor konfigurací a konfigurační skripty vč. VLANStore+*FAC_CONFACT (LOG_LOCAL0+4) - aktivátor konfigurací a konfigurační skripty vč. VLANStore a mazače konfigurací laboratorních prvků
*FAC_TUNSRV (LOG_LOCAL0+5) - tunelovací server *FAC_TUNSRV (LOG_LOCAL0+5) - tunelovací server
*FAC_ERASESRV (LOG_LOCAL0+6) - mazací server *FAC_ERASESRV (LOG_LOCAL0+6) - mazací server
-* Zbývá 9 dalších hodnot (celkem je 5b pro facility, LOG_LOCAL0 je 16)+*FAC_ACTSRV (LOG_LOCAL0+7) - aktivační server
 +* Zbývá 8 dalších hodnot (celkem je 5b pro facility, LOG_LOCAL0 je 16)
-=== Sjednocený formát textů logovaných zpráv ===+=== Údaje, které potřebujeme ukládat ===
 +:
 +* timestamp
 +* facility, debug level
 +* Jméno lokality generující komponenty
 +* jméno programu příslušného serveru komponenty
 +* PID
 +* source file & line (v levelu DEBUG a ERROR)
 +* Vysvětlující text - jednořádkový, '''pro srozumitelnost potenciálním cizincům v angličtině'''. Text může mj. obsahovat tyto významné údaje:
 +** Partnerská lokalita - při komunikačních akcích, nutná možnost snadného vyhledání pro zasílání chybových zpráv a informace správci přislušné lokality
 +** Transaction ID (XID)
-=== Knihovní funkce pro logování 2 === 
-<nowiki> 
-man logger 
-man 3 syslog: 
-void openlog(const char *ident, int option, int facility); 
-openlog("msg-prepend-string",LOG_NDELAY|LOG_CONS|LOG_PID, int facility (LOG_USER)); 
-void syslog(FACILITY | PRIORITY , const char *format, ...);+=== Formát logovacích zpráv ===
-man 3 setlogmask:+Formát logovacích zpráv je částečně předurčen formátem používaných Syslogem.
-int setlogmask(int mask);+'''Timestamp''' a '''IP adresu/hostname zdroje''' zprávy dodá Syslogd, '''PID''' dodá systémová funkce vsyslog() volaná z naší unifikované logovací funkce '''VLLOG()'''. Facility se nastaví pro program jedenkrát z '''initLogging()''' (hodnota se vezme ze souboru vl-debug.h a bude se používat jako default ve volanich VLLOG(), kde pak už stačí uvádět jen debug level).
- - bitovým součtem se určí úrovně, které se mají funkcí syslog() skutečně logovat+
-</nowiki> 
- A process has a log priority mask that determines which calls to sys-+Formát zpráv v souboru vytvářeném syslogd vypadá takto:
- log(3) may be logged. All other calls will be ignored. Logging is+
- enabled for the priorities that have the corresponding bit set in mask.+
- The initial mask is such that logging is enabled for all priorities.+
 +DATE TIME SOURCE-HOST PROGRAM-ID[PID]: MSGTEXT
 +PROGRAM-ID je tvořen složením jména lokality a názvu programu (spustitelného souboru), vzájemně oddělených #. V případě řídící webové aplikace se jako jméno programu použije řetězec "WWW" (později může být doplněno o další rozlišení části webové aplikace použitím různých suffixů). Jméno lokality se načte při inicializaci logovacího systému funkcí '''initLogging()''' ze souboru '''/etc/sitename'''; lze jej také (s vyšší prioritou) nastavit parametrem příkazového řádku '''-DBGLOGsite=jmeno'''.
- +=== Sjednocený formát popisných textů logovaných zpráv ===
 +Pro usnadnění strojového zpracování je formát popisných textů hlášení (MSGTEXT) sjednocen takto:
 +DEBUGLEVEL {[filename:line]} : Free-form-English-Message
 +
 +kde DEBUGLEVEL={ EMERG | ALERT |CRIT | ERR | WARNING | NOTICE | INFO | DEBUG }
 +
 +'''Uživatel do funkce VLLOG() zadává pouze Free-form-English-Message, zbytek generuje funkce VLLOG().'''
 +
 +Je-li DEBUGLEVEL roven DEBUG nebo ERROR, následuje za identifikátorem DEBUGLEVEL odděleným mezerou jméno a řádek zdrojového souboru ve tvaru [filename:line].
 +
 +Je zavedena konvence, že
 +* pokud hlášení informuje o dění v partnerské lokalitě, je její jméno uvozeno takto: >>SITENAME<<.
 +* pokud se uvádí XID (a nejedná-li se o dump protokolové zprávy, který se provádí bez modifikací), uvádí se ve tvaru <nowiki>[[XIDvalue]]</nowiki>
 +* sekvencím <nowiki><<,>>,[[,]]</nowiki> se jinak v textu hlášení vyhýbáme
 +
 +Lze také použít sekvenci '''%m''', která uloží popisný text k poslední systémové chybě (viz man syslog).
 +
 +=== Knihovní funkce pro logování ===
 +
 +Abychom dosáhli jednotné a pro programátory bezpracné nastavení úrovně logování u každého programu, vytvořili jsme několik pomocných funkcí v C, které se ke každému serveru přilinkují (stačí staticky, mají pár set bytes). Jedná se o inicializační funkci, funkci pro zalogování zprávy, a funkci pro zalogování informací o neočekávané chybě.
 +
 +'''Hlavičky všech funkcí jsou ve vl-debug.h''', těla v vl-debug.c. V souboru '''vl-debug-test.c''' je '''příklad použití''' všech možností debug/log systému.
 +
 +
 +U PHP kódu předpokládáme nastavení úrovně debugování ve vhodném .php souboru, který se pomocí include připojuje ke všem .php souborům (soubor s konstantami, soubor s autentizací ?).
 +
 +=== Ošetření neočekávaných chyb ===
 +
 +Přiznejme si, že není možné ošetřit úplně všechno (i když se budeme snažit). Nicméně bychom měli aspoň vědět o tom, že vyvstal problém tam, kde jsme jej nečekali a kde přesně do bylo. Pokud tedy nějaká systémová funkce vrací chybový kód, který nechceme dále rozlišovat, protože jeho vrácení prostě nepředpokládáme, budeme volat '''před použitím jakéhokoli dalšího systémového volání''' (aby se nepřepsala hodnota proměnné errno) funkci '''LOG_UNEXPECTED_SYS_ERROR()''' (viz [https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/COMMON/src/vl-debug.c vl-debug.c]), která zaloguje kód a vysvětlující text chyby ('''strerror(errno)''') spolu se jménem zdrojového kódu a číslem řádku, na kterém je volání LOG_UNEXPECTED_SYS_ERROR() umístěno. Obdobným způsobem ošetřujeme uživatelské funkce, které nenastavují errno, pouze s tím rozdílem, že použijeme funkci '''LOG_UNEXPECTED_USR_ERROR(errcode)''', jejímž parametrem je právě neočekávaný chybovž kód uživatelské funkce (tedy typický zápis bude '''LOG_UNEXPECTED_USR_ERROR(UserFunc(...));''' ). Pokud je errcode, resp. předaný parametr 0, obě funkce nedělají nic.
 +
 +
 +=== Pomocná debug hlášení pro základní ladění (tracing) ===
 +
 +'''Do informací zasílaných na Syslog nebudeme míchat debug hlášení pro základní ladění''' (trasování kódu programu, typicky posílané pomocí printf na stdout během ladění). Aby program neobsahoval množství těchto zapomenutých ladících printf(), zavedeme konvenci, že '''veškerá takováto hlášení budou vypisovány výhradně funkcí DBGPRINTF'''. Tu dokážeme snadno ve zdrojových kódech na základě názvu jednak snadno najít a případě odstranit, ale hlavně '''povolit či zakázat její efekt''' tím, že ji (pomoci #define ve [https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/COMMON/include/vl-debug.h vl-debug.h]) budeme definovat jako funkci printf nebo nullprintf s prázdným tělem '''podle toho, zda je před připojením souboru vl-debug.h definován symbol DEBUG''' (při ladění musí být, #define VDEBUG).
 +
 +
 +
 +=== Nastavení syslog démona - logovací soubory ===
 +
 +('''Syslog''') /etc/syslog.conf:
 +<pre>
 +facility.debuglevel path_to_logfile
 +facility.debuglevel *hostname.to.forward
 +
 +mail.err /var/log/mail.err
 +</pre>
 +* Lze použít * na místě facility i debuglevel
 +* Rovnitko pred debuglevel rika, ze se tyka jen jedne urovne, jinak teto a vyssich.
 +
 +('''Syslog-ng''') /etc/syslog-ng/syslog-ng.conf:
 +<pre>
 +source s_all {
 + # message generated by Syslog-NG
 + internal();
 +
 + # standard Linux log source (this is the default place for the syslog() function to send logs to)
 + unix-stream("/dev/log");
 +
 + # messages from the kernel
 + file("/proc/kmsg" log_prefix("kernel: "));
 +
 + # use the following line if you want to receive remote UDP logging messages (this is equivalent to the "-r" syslogd flag)
 + udp();
 +};
 +
 +filter f_local0 { facility(local0); };
 +
 +destination d_virtlab { file("/var/log/virtlab.log"); };
 +
 +log {
 + source(s_all);
 + filter(f_local0);
 + destination(d_virtlab);
 +};
 +</pre>
 +* '''source''' určuje zdroj syslog zprav
 +* '''destination''' určuje, kam se mají zpravy ukládat
 +* '''filter''' provede filtraci zprav podle zadaných parametrů
 +
 +
 +Spise nez logovat do ruznych souboru je treba logovat do mysql, a tam to "nejak" upravit( slozene informace rozlozit) a zobrazovat. Jak rozchodit syslog-ng aby logoval do mysql je popsano na http://gentoo-wiki.com/HOWTO_setup_PHP-Syslog-NG nebo na http://www.vermeer.org/display_doc.php?doc_id=1
 +;Strucny navod logovani z syslog-ng do mysql
 +# stahnout phpsyslogng z http://sourceforge.net/projects/php-syslog-ng/
 +# nainstalovat, upravit soubor ''config.php''
 +# vytvorit db podle souboru ''dbsetup.sql''
 +# vytvorit pipe (pojmenovanou pipu/pajpu) ''mkfifo /var/log/mysql.pipe''
 +# upravit soubor ''/etc/syslog-ng/syslog-ng.conf'' : ukazka
 + #syslog-ng conf file for use with phpsyslog-ng
 + destination d_mysql { program("/usr/bin/mysql --user=syslogfeeder --password=PASSWORD syslog < /var/log/mysql.pipe"); pipe ("/var/log/mysql.pipe" template("INSERT INTO logs (host, facility, priority, level, tag, datetime, program, msg) VALUES ( '$HOST', '$FACILITY', '$PRIORITY', '$LEVEL', '$TAG', '$YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC','$PROGRAM', '$MSG' );\n") template-escape(yes)); };
 + source src { unix-stream("/dev/log"); pipe("/proc/kmsg"); udp(); tcp(); internal(); };
 + log { source(src); destination(d_mysql); };
 +;popis ukazky
 +* prvni radek
 +*: urcuje kam se bude logovat, data se zapisou do pipe (pajpy/pipy) ''/var/log/mysql.pipe'', uprav to podle sablony(jako sql insert), a spust program ktery zapise obsah pipy do mysql
 +* druhy radek
 +*: urci odkud se budou brat logy
 +* treti radek
 +*: urci co se ma kam logovat, je mozne pridat jeste filtr a tedy ''dulezite'' info posilat na mail/sms. Filtr se da psat jako regularni vyraz(vypocetne narocnejsi)
 +;Nutno zabezpecit
 +* bezici mysql server : uprava ''/etc/init.d/syslog-ng'' do start sekce pridat start mysql(pro jistotu)
=== Skripty/konfigurace syslog-ng pro přeposílání kritických zpráv administrátorům příslušných lokalit === === Skripty/konfigurace syslog-ng pro přeposílání kritických zpráv administrátorům příslušných lokalit ===
 +staci upravit configuracni soubor syslog-ng. do logovaci sekce pridat filter
 +
 +;syslog-ng faq
 +: http://www.campin.net/syslog-ng/faq.html
 +: http://sial.org/howto/logging/syslog-ng/
 +: CESKY http://www.abclinuxu.cz/blog/dw/2007/7/25/187781
 +;ukazka konfiguraku
 +: http://www.campin.net/syslog-ng.conf
 +
 +Bude doplněno.
 +
=== Konfigurace lokálních proxy syslog-ng pro přeposílání zpráv na hlavní syslog server lokality === === Konfigurace lokálních proxy syslog-ng pro přeposílání zpráv na hlavní syslog server lokality ===
 +Bude doplněno.
 +
 +== Logování v PHP skriptech ==
 +Pro logování a debug ve skriptech PHP je rovněž vytvořena sada funkcí. Jsou uloženy v souboru [https://svn.cs.vsb.cz/svn/virtlab/DISTR/web/logging/vl-debug.php vl-debug.php].
 +
 +Na začátku každého php skriptu, kde budeme využívat logování, načteme skript '''vl-debug.php'''.
 +
 +K otestování návratové hodnoty uživatelské funkce pak použijeme funkci '''LOG_UNEXPECTED_USR_ERROR(navratova_hodnota,__LINE__);'''
 +Narozdíl od stejnojmenné funkce v C, je zde nutné uvést číslo řádku - pomocí předdefinované konstanty __LINE__.
 +
 +Jakákoliv chyba, která se ve skriptu vyskytne je automaticky odchycena a zpracována (uložena do logu) funkcí '''LOG_UNEXPECTED_SYS_ERROR'''. Tu tedy '''není nutné explicitně volat'''.
 +
 +Pro logování různých úrovní "chyb" použijeme funkci '''VLLOG($uroven,__LINE__,"textova zprava")'''. Ta má oproti verzi v C ještě navíc parametr __LINE__.
 +
 +Pro pomocná debug hlášení slouží '''DBGPRINTF($formatovaci_retezec,[$dalsi_argumenty,[....]])'''. Vyžaduje argumenty stejným způsobem jako např. funkce printf()
 +
 +Debug výpis se dá vypnout/zapnout podle nastavení konstanty '''VDEBUG''' v souboru [https://svn.cs.vsb.cz/svn/virtlab/DISTR/web/logging/vl-debug-const.php vl-debug-const.php]. V tomto souboru se nastavuje také úroveň logování.
 +
 +Příklad použití je v souboru [https://svn.cs.vsb.cz/svn/virtlab/DISTR/web/logging/vl-debug-test.php vl-debug-test.php].
 +
 +== Logování ve shell skriptech ( bash ) ==
 +
 +Pro záznam hlášení na Syslog ze shell skriptů používáme funkci '''VLLOG''' z [https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/COMMON/src/vl-debug.sh COMMON/src/vl-debug.sh].
 +Logováni musí být nejprve inicializováno funkcí '''INITLOGGING FAC_xxx''' (nastavení implicitní facility).
 +
 +Syntaxe VLLOG je
 + '''VLLOG {emerg|alert|crit|err|info|notice|warning|debug } TEXT'''
 +
 +V levelu debug se automaticky do zprávy zaloguje i jméno skriptu a aktuální řádek.
 +
 +Pro realizaci se používá systémového programu '''logger'''.
 +
 +Úrovně, které se mají pro jednotlivé facility logovat, jsou nastaveny v souboru '''/etc/virtlab/shell-logging.conf'''. Syntaxe viz [https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/logging/src/shell-logging.conf příklad].
 +
 +Příklad použití viz [https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/logging/src/vl-debug-test.sh vl-debug-test.sh].
 +
 +'''Není-li zavoláno INITLOGGING a promenna VGLLOG_FACILITY není nastavena (zděděna), nastavuje se na VLLOG_UNDEFINED a zprávy se logují s facility local8.'''
 +
 +== Tracing shell skriptů ==
 +
 +* Zapnutí výpisu provedených příkazů: do #!/bin/bash na prvním řádku skriptu přidat -x
 +* Zapnutí výpisu čísel řádků: před spuštěním skriptu export PS4='line $LINENO: '
 +
 +
 +Další viz http://www.unix.org.ua/orelly/unix/ksh/ch09_01.htm
 +
 +== Logování v Perl skriptech ==
 +
 +viz [https://svn.cs.vsb.cz/svn/virtlab/DISTR/src/COMMON/src/vl-debug.pl vl-debug.pl]
 +
 +== Ukladani zaznamu, ohlasovani chyb e-mailem ==
 +
 +Od loggingu ocekavame toto:
 +
 +* Log hlaseni generovana komponentami urcite lokality by se mely automaticky zaznamenavat do souboru syslogu teto lokality. A to vcetne identifikace facility a debugLevelu
 +* Log hlaseni generovana komponentami urcite lokality od urciteho nastaveneho debugLevelu vyse by se mely take kopirovat na emailovu adresu prirazenou lokalite pro "urgentni" zpravy. Ty se budou preposilat na SMS, takze by mely byt formatovany tak, aby clovek na mobilu z toho neco videl. Je nutne osetrit pripad, aby se od jedne chyby nevysypala zaplava SMS.
 +* Pokud se v textu zpravy objevi >>JMENOLOKALITY<<, preposle se zprava jeste na emailovou adresu spravce teto lokality (cili dalsi konfigurak). Jedna se o situace, kdy se v lokalite X stane neco, co se tyka lokality JMENOLOKALITY.
 +
 +Jinak potrebujeme, abychom byli schopni snadno sledovat sledy akci, ktere se v ramci jedne transakce deji na ruznych komponentach. To se nam bude velmi spatne delat, pokud ten logging bude rozhazeny do mnoha souboru nebo nekde v MySQL. Osobne soudim, ze nejlepe se veci hledaji GREPem. Proto v prvni fazi navrhuji sypat vsechno do jednoho textoveho logu a samozrejme u kazde zpravy zapisovat facility i debugLevel. Paralelne s tim mozno do MySQL a nahodit pro vzdalene prohlizeni PHPMyEdit.
 +
 +V mysql logovat do 1 tabulky, a v ni udrzovat jen poslednich (treba) 7 dni, v archivni tabulce treba posledni mesic.
 +
 +== Ohlasovani chyb e-mailem ==
 +
 +Pro logování jednotlivých komponent se používá programu syslog-ng. Tento program je velice flexibilní a umožňuje rozdělovat jednotlivé stupně závažnosti (priority) zpráv a zdroje zpráv (facility) do různých textových souborů. Pro projekt Virtlab je potřeba aby níže specifikované zpravy byly doručeny na email správců Virtlab-u a aby byl vložen záznam o chybě do systému pro zprávu chyb (VirtIS) . Zprávy, o které se budeme zajímat, jsou určeny úrovní závažnosti (priority) a tato závažnost je z rozsahu "crit".."emerg".
 +
 +Konfigurační soubor syslog-ng má standardní umístění "/etc/syslog-ng/syslog-ng.conf". V tomto souboru je třeba nastavit aby syslog-ng požadované zprávy dále zpracovával způsobem, který specifikujeme. Nastavení programu syslog-ng se skládá ze tří částí.
 +
 +V první části je třeba specifikovat "filtr" tedy specifikovat zprávy, o které máme zájem. Pro specifikaci filtru je potřeba vytvořit novou sekci "filter" a tato sekce je pojmenována "f_na_email". Ve filtru určíme priority zpráv, které se mají propustit. Příkazem "level( crit .. emerg );". Tyto priority se budou dále zpracovávat. Sekci "filter f_na_email" je třeba ukončit.
 +
 +Dále je třeba vytvořit sekci ktera specifikuje kam se budou zaznamenané (zalogované) informace ukládat. Sekce typu "destination". Pojmenování sekce je "d_na_email". Standardní možnost je ukládat tyto informace do souboru a ten číst. Toto je nepraktické z důvodu náročnosti na software, který by měl číst takto vytvořený soubor. Proto je použita možnost ukládat informace (záznamy) do fifo souboru (souborová routa) a spustit obslužný software, který bude z fifo souboru záznamy vybírat.
 +
 +Poslední sekce propojí výše popsané sekce. Výsledná konfigurace bude následující. Ze všech záznamu v syslog-ng vyber ty které mají prioritu v rozmezí "crit" a "emerg". Tyto záznamy vlož do fifo souboru. Při spuštění syslog-ng spusť program mailsender2.sh, který bude vybírat záznamy z fifo souboru a bude je dále zpracovávat.
 +
 +Další část odesílání záznamu na email a do systému pro zprávu chyb (bugtracking systém) je program mailsender2.sh, ktery je umístěný v adresáři /opt/virtlab/service/mailsender/. Tento program vybírá logovací záznamy z fifo souboru (kam je ukládá syslog-ng) a připraví je do souboru "aktualni-email", který se pravidelně odesílá programem "email-it".
 +
 +Program "email-it" zpracovává soubor "aktualni-email" a v případě, že existuje jej zabalí spolu s kopií "syslog" souboru do archivu a tento archiv posle elektronickou poštou na definovány email. Dále založí v bugtracking systému (systém pro zprávu chyb) novy záznam pro chybu, kde rovněž přiloží výše zmíněný zabalený soubor. Tento program je spouštěn pomocí programu "cron" pravidelně co hodinu. Tímto způsobem je zajištěna agregace zpráv a maximálně jednou za hodinu se vytvoří záznam chyby do bugtracking systému a odešle se email o chybě.
 +
 +
 +
 +konfigurace syslog-ng potrebna pro odesilani emailu
 +
 + destination d_na_email {
 + #format
 + #Dec 11 13:02:15 ostrava ostrava#cons-server[20942]: CRIT [src/server.c:140] : Cannot read value from file [/tmp/appletchecker13451696420942]
 + #$YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC $HOST $PROGRAM $PRIORITY $MSG
 + program( "/opt/virtlab/service/mailsender/mailsender2.sh" ); pipe( "/opt/virtlab/service/mailsender/mail.fifo" template( "$PRIORITY $YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC $HOST $PROGRAM $PRIORITY $MSG\n" ) );
 + };
 + filter f_na_email {
 + level( crit .. emerg );
 + };
 + log {
 + source(s_all);
 + filter(f_na_email);
 + destination(d_na_email);
 + };
 +
 +*syslog-ng posila zpravy do souborove roury jmenem /opt/virtlab/service/mailsender/mail.fifo
 +*dale je potreba soubor mailsender2.sh ktery je ulozeny /opt/virtlab/service/mailsender/mailsender2.sh
 +*tento soubor presune zpravu ze souborove roury do normalniho souboru ktery je jednou za hodinu odeslan na email
 +*odesilani jednou za hodinu zajistuje cron ktery spusti skript /opt/virtlab/service/mailsender/email-it
 +*na ktery email se ma odesilat je definovano v email-it skriptu
 +
 +
 +
 +
 +
 +
 +[[Kategorie:Komponenty virtlabu]]

Aktuální verze

Obsah

[editovat]

Logování a debugging

Pro odladění, sledování provozu a řešení incidentů celého distribuovaného systému virtuální laboratoře je nutný konzistentní systém ukládání informací o běhu na různých úrovních, které bude možné snadno automaticky vyhodnocovat a informovat příslušné správce o kritických nebo nestandardních stavech. Informace o běhu všech komponent (serverů) lokality budou shromažďovány na Syslog serveru dané lokality, kde budou vyhodnocovány vhodnými skripty nebo prostředky syslog démona či pomocí phpsyslogng a podle nastavených pravidel případně přeposílány emailem na správné zodpovědné správce. Logovací soubory/databáze syslog serverů všech lokalit budou zpřístupněny pro čtení správcům všech ostatních lokalit (patrně přes WWW).

Z důvodu snadné implementace návazných rozšiření bude použit Syslog Next Generation (Syslog-ng).

Jednotlivé servery systému budou zasílat debug informace na syslog jednotně pomocí k tomu účelu vytvořené univerzální logovací funkce (C), kterou budou formou knihovny přilinkovávat (PHP bude volat jako externí program nebo bude vytvořen ekvivalent v PHP). Funkce zformátuje hlášení dohodnutým způsobem a předá jej Syslog serveru lokality (démonu Syslog-ng), s ohledem na případné parametry nastavení logovacího režimu na příkazovém řádku (resp. konfiguračního souboru v případě PHP).

Parametry příkazového řádku související s debuggingem budou pro všechny servery sjednoceny (přilinkováním k tomu účelu vytvořené parsovací inicializační funkce v C).

V případě, že budou servery lokality distribuovány na více strojů, bude na každém z nich instalován proxy syslog démon, který bude nastaven tak, aby zprávy pouze přeposílal na hlavní Syslog démon lokality.


[editovat]

Sledování distribuovaných transakcí

Abychom mohli v log souborech dostopovat sekvenci souvisejících záznamů o akcích, které se provedly jako důsledek nějakého jednoho požadavku iniciovaného uživatelem (nebo i systémem, typicky od časovače), budeme v protokolech všech serverů označovat požadavky i odpovědi tzv. identifikátorem transakce (XID). Identifikátor transakce bude hodnota ve tvaru XID=value (nebo např. XID:value podle požadavků příslušného protokolu) umístěná mezi volitelnými parametry v hlavičce všech požadavků, resp. odpovědi na požadavky. Hodnotu identifikátoru transakce vymyslí jednoznačně iniciátor transakce (obvykle WWW aplikace) a ostatní servery ji budou pouze vracet v odpovědích, resp. kopírovat do požadavků, které vytvoří jako reakci na příchozí požadavek s daným XID. A samozřejmě také logovat do log souborů. XID bude řetězec, způsob vytváření bude sjednocen takto:

název_lokality.konstanta_facility.ResID.UserID.unix_timestamp.

Je-li akce inicována systémovou komponentou, např. od časovače, místo jména uživatele bude řetězec #SYS#. Pokud ResID nebo UserID není znám, použije se řetězec RUnknowm, resp. UUnknown.

[editovat]

Unifikované nastavení chování logování

Úroveň debuggingu všech serverů (mimo WWW aplikace - tam pomocí vhodného .inc souboru) lze určit pomocí jednotného systému parametrů předávaných z příkazové řádky. Parametry jsou koncipovány tak, aby mohly být zpracovány společnou inicializační funkcí přilinkovávanou ke každému serveru a následně automaticky odstraněny, aby neposouvaly pořadí a neovlivńovaly počet základních parametrů očekávaných programem. Jména jednotných parametrů nastavujících úroveň debuggingu začínají vždy řetězcem -DBGLOG a mají tvar -DBGLOGxxx, resp. -DBGLOGxxx=hodnota. Na jejich pořadí včetně případném promísení s "normálními" parametry programu nezáleži. Načtení a odstranění debug parametrů se provede pomocí inicializační funkce initLogging(argc*,argv,facilityID) (vl-debug.c), která se volá vždy jako první příkaz v main(), tj. ještě před pokusem o parsování parametrů příkazové řádky vlastního programu. FacilityID viz vldebug.h.


Momentálně jsou definovány tyto parametry:


  • -DBGLOGsite=x - nastaveni jmena mistni lokality (jen pro ucely logovani). Implicitne se bere s /etc/sitename.
  • -DBGLOGlevel={EMERG|ALERT|CRIT|ERR|WARNING|NOTICE|INFO|DEBUG} - od kterého debug levelu se mají hlášení skutečně posílat na Syslog. Pokud není explicitně nastaveno, použije se LOG_CRIT.

Možná ješte doplníme -DBGLOG-actions=xxx blíže určující, jaké "typy" informací se maji ukladat v levelu debug (DB access, mezikomponentová komunikace, forking/exitting procesů, info o běhu algoritmů, ...) ???


[editovat]

Úrovně logování

Úrovně logování (priority hlášení) jsou částečně předurčeny logikou zavedenou Syslogem:

  • LOG_EMERG (system is unusable)
  • LOG_ALERT (action must be taken immediately)
  • LOG_CRIT (critical conditions)
  • LOG_ERR (error conditions)
  • LOG_WARNING (warning conditions)
  • LOG_NOTICE (normal, but significant, condition)
  • LOG_INFO (informational message)
  • LOG_DEBUG (debug-level message)

Z úrovní Syslogu využíváme následující úrovně:


  • Aktuální zjednodušení v serverových komponentách v C++:
    • CRIT - výpadek komponenty (vhodný k posílání SMS administrátorům)
    • INFO - stručné informace o probíhajících zásadních akcích/událostech
    • WARNING - zotavitelená chyba (důvod jejíhož by se nicméně měl analyzovat)
    • DEBUG - detailní ladící informace o probíhajících akcích/událostech, včetně parametrů.


  • Původní (příliš složitý) plán:
    • LOG_DEBUG - info o akcích a interakcích komponent systému a stavech algoritmů - podrobné (doplňující LOG_INFO], vč. parametrů, dump zpráv vyměňovaných mezi komponenty, výpis přijatých a odeslaných dat, forking & exiting dynamicky vytvářených podprocesů, info o databázových operacích (texty prováděných SQL příkazů).
    • LOG_INFO - info o zásadních akcích a interakcích komponent systému a stavech algoritmů (došlé požadavky a reakce na ně, výsledky výpočtů, spouštění akcí od časovače), - jednořádkové
    • LOG_NOTICE - info o komunikačních akcích - přijatá a navázaná spojení + chyby,
    • LOG_WARNING - info o chybách, ze kterých se systém zotavil
    • LOG_ERR - ignorované neočekávané chyby vrácené ze systémových. resp. uživatelských volání (neošetřené)- Generují se použitím pomocně vytvořených funkcí LOG_UNEXPECTED_SYS_ERROR, resp. LOG_UNEXPECTED_USR_ERROR(errcode). Text vygenerované zprávy pak bude obsahovat jméno a řádek zdrojového kódu, kde chyba vznikla, u funkce LOG_UNEXPECTED_SYS_ERROR popisné hlášení chyby generované funkcí perror() na základě globální proměnné errno a u funkce LOG_UNEXPECTED_USR_ERROR číslo chyby předané jako argument. Mezi voláním ošetřované funkce a voláním LOG_UNEXPECTED_SYS_ERROR nesmí být volána jiná systémová volání, která by změnila obsah errno.
    • LOG_CRIT (critical conditions) - informace o výpadku některých komponent vyžadující okamžitý administrátorský zásah (výpadek části systému). Taktéž problémy se startem komponent způsobené špatnou konfigurací.
    • LOG_ALERT - informace o stavech způsobených chybou v kódu vyžadující odstranění chyby přeprogramováním


Facilities určují v Syslogu zdroj, resp. v našem případě komponentu, která vygenerovala hlášení. Používané (číselné) identifikátory facilities a synonyma použivaná pro jednotlivé facilities jsou v souboru vl-debug.h:

  • FAC_WWWAPP (LOG_LOCAL0) - webová aplikace řídícího serveru lokality (GUI, mapovací algoritmus)
  • FAC_RSVSRV (LOG_LOCAL0+1) - rezervační server
  • FAC_CONSSRV (LOG_LOCAL0+2) - konzolový server
  • FAC_CONFSRV (LOG_LOCAL0+3) - konfigurační server
  • FAC_CONFACT (LOG_LOCAL0+4) - aktivátor konfigurací a konfigurační skripty vč. VLANStore a mazače konfigurací laboratorních prvků
  • FAC_TUNSRV (LOG_LOCAL0+5) - tunelovací server
  • FAC_ERASESRV (LOG_LOCAL0+6) - mazací server
  • FAC_ACTSRV (LOG_LOCAL0+7) - aktivační server
  • Zbývá 8 dalších hodnot (celkem je 5b pro facility, LOG_LOCAL0 je 16)
[editovat]

Údaje, které potřebujeme ukládat

  • timestamp
  • facility, debug level
  • Jméno lokality generující komponenty
  • jméno programu příslušného serveru komponenty
  • PID
  • source file & line (v levelu DEBUG a ERROR)
  • Vysvětlující text - jednořádkový, pro srozumitelnost potenciálním cizincům v angličtině. Text může mj. obsahovat tyto významné údaje:
    • Partnerská lokalita - při komunikačních akcích, nutná možnost snadného vyhledání pro zasílání chybových zpráv a informace správci přislušné lokality
    • Transaction ID (XID)


[editovat]

Formát logovacích zpráv

Formát logovacích zpráv je částečně předurčen formátem používaných Syslogem. Timestamp a IP adresu/hostname zdroje zprávy dodá Syslogd, PID dodá systémová funkce vsyslog() volaná z naší unifikované logovací funkce VLLOG(). Facility se nastaví pro program jedenkrát z initLogging() (hodnota se vezme ze souboru vl-debug.h a bude se používat jako default ve volanich VLLOG(), kde pak už stačí uvádět jen debug level).


Formát zpráv v souboru vytvářeném syslogd vypadá takto:

DATE TIME SOURCE-HOST PROGRAM-ID[PID]: MSGTEXT


PROGRAM-ID je tvořen složením jména lokality a názvu programu (spustitelného souboru), vzájemně oddělených #. V případě řídící webové aplikace se jako jméno programu použije řetězec "WWW" (později může být doplněno o další rozlišení části webové aplikace použitím různých suffixů). Jméno lokality se načte při inicializaci logovacího systému funkcí initLogging() ze souboru /etc/sitename; lze jej také (s vyšší prioritou) nastavit parametrem příkazového řádku -DBGLOGsite=jmeno.

[editovat]

Sjednocený formát popisných textů logovaných zpráv

Pro usnadnění strojového zpracování je formát popisných textů hlášení (MSGTEXT) sjednocen takto:

DEBUGLEVEL {[filename:line]} : Free-form-English-Message

kde DEBUGLEVEL={ EMERG | ALERT |CRIT | ERR | WARNING | NOTICE | INFO | DEBUG }

Uživatel do funkce VLLOG() zadává pouze Free-form-English-Message, zbytek generuje funkce VLLOG().

Je-li DEBUGLEVEL roven DEBUG nebo ERROR, následuje za identifikátorem DEBUGLEVEL odděleným mezerou jméno a řádek zdrojového souboru ve tvaru [filename:line].

Je zavedena konvence, že

  • pokud hlášení informuje o dění v partnerské lokalitě, je její jméno uvozeno takto: >>SITENAME<<.
  • pokud se uvádí XID (a nejedná-li se o dump protokolové zprávy, který se provádí bez modifikací), uvádí se ve tvaru [[XIDvalue]]
  • sekvencím <<,>>,[[,]] se jinak v textu hlášení vyhýbáme

Lze také použít sekvenci %m, která uloží popisný text k poslední systémové chybě (viz man syslog).

[editovat]

Knihovní funkce pro logování

Abychom dosáhli jednotné a pro programátory bezpracné nastavení úrovně logování u každého programu, vytvořili jsme několik pomocných funkcí v C, které se ke každému serveru přilinkují (stačí staticky, mají pár set bytes). Jedná se o inicializační funkci, funkci pro zalogování zprávy, a funkci pro zalogování informací o neočekávané chybě.

Hlavičky všech funkcí jsou ve vl-debug.h, těla v vl-debug.c. V souboru vl-debug-test.c je příklad použití všech možností debug/log systému.


U PHP kódu předpokládáme nastavení úrovně debugování ve vhodném .php souboru, který se pomocí include připojuje ke všem .php souborům (soubor s konstantami, soubor s autentizací ?).

[editovat]

Ošetření neočekávaných chyb

Přiznejme si, že není možné ošetřit úplně všechno (i když se budeme snažit). Nicméně bychom měli aspoň vědět o tom, že vyvstal problém tam, kde jsme jej nečekali a kde přesně do bylo. Pokud tedy nějaká systémová funkce vrací chybový kód, který nechceme dále rozlišovat, protože jeho vrácení prostě nepředpokládáme, budeme volat před použitím jakéhokoli dalšího systémového volání (aby se nepřepsala hodnota proměnné errno) funkci LOG_UNEXPECTED_SYS_ERROR() (viz vl-debug.c), která zaloguje kód a vysvětlující text chyby (strerror(errno)) spolu se jménem zdrojového kódu a číslem řádku, na kterém je volání LOG_UNEXPECTED_SYS_ERROR() umístěno. Obdobným způsobem ošetřujeme uživatelské funkce, které nenastavují errno, pouze s tím rozdílem, že použijeme funkci LOG_UNEXPECTED_USR_ERROR(errcode), jejímž parametrem je právě neočekávaný chybovž kód uživatelské funkce (tedy typický zápis bude LOG_UNEXPECTED_USR_ERROR(UserFunc(...)); ). Pokud je errcode, resp. předaný parametr 0, obě funkce nedělají nic.


[editovat]

Pomocná debug hlášení pro základní ladění (tracing)

Do informací zasílaných na Syslog nebudeme míchat debug hlášení pro základní ladění (trasování kódu programu, typicky posílané pomocí printf na stdout během ladění). Aby program neobsahoval množství těchto zapomenutých ladících printf(), zavedeme konvenci, že veškerá takováto hlášení budou vypisovány výhradně funkcí DBGPRINTF. Tu dokážeme snadno ve zdrojových kódech na základě názvu jednak snadno najít a případě odstranit, ale hlavně povolit či zakázat její efekt tím, že ji (pomoci #define ve vl-debug.h) budeme definovat jako funkci printf nebo nullprintf s prázdným tělem podle toho, zda je před připojením souboru vl-debug.h definován symbol DEBUG (při ladění musí být, #define VDEBUG).


[editovat]

Nastavení syslog démona - logovací soubory

(Syslog) /etc/syslog.conf: 

facility.debuglevel    path_to_logfile
facility.debuglevel    *hostname.to.forward

mail.err    /var/log/mail.err
  • Lze použít * na místě facility i debuglevel
  • Rovnitko pred debuglevel rika, ze se tyka jen jedne urovne, jinak teto a vyssich.

(Syslog-ng) /etc/syslog-ng/syslog-ng.conf: 

source s_all {
        # message generated by Syslog-NG
        internal();

        # standard Linux log source (this is the default place for the syslog() function to send logs to)
        unix-stream("/dev/log");

        # messages from the kernel
        file("/proc/kmsg" log_prefix("kernel: "));

        # use the following line if you want to receive remote UDP logging messages (this is equivalent to the "-r" syslogd flag)
        udp();
};

filter f_local0 { facility(local0); };

destination d_virtlab { file("/var/log/virtlab.log"); };

log {
        source(s_all);
        filter(f_local0);
        destination(d_virtlab);
};
  • source určuje zdroj syslog zprav
  • destination určuje, kam se mají zpravy ukládat
  • filter provede filtraci zprav podle zadaných parametrů


Spise nez logovat do ruznych souboru je treba logovat do mysql, a tam to "nejak" upravit( slozene informace rozlozit) a zobrazovat. Jak rozchodit syslog-ng aby logoval do mysql je popsano na http://gentoo-wiki.com/HOWTO_setup_PHP-Syslog-NG nebo na http://www.vermeer.org/display_doc.php?doc_id=1

Strucny navod logovani z syslog-ng do mysql
  1. stahnout phpsyslogng z http://sourceforge.net/projects/php-syslog-ng/
  2. nainstalovat, upravit soubor config.php
  3. vytvorit db podle souboru dbsetup.sql
  4. vytvorit pipe (pojmenovanou pipu/pajpu) mkfifo /var/log/mysql.pipe
  5. upravit soubor /etc/syslog-ng/syslog-ng.conf : ukazka 
 #syslog-ng conf file for use with phpsyslog-ng
 destination d_mysql { program("/usr/bin/mysql --user=syslogfeeder --password=PASSWORD syslog < /var/log/mysql.pipe"); pipe ("/var/log/mysql.pipe" template("INSERT INTO logs (host, facility, priority, level, tag, datetime, program, msg) VALUES ( '$HOST', '$FACILITY', '$PRIORITY', '$LEVEL', '$TAG', '$YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC','$PROGRAM', '$MSG' );\n") template-escape(yes)); };
 source src { unix-stream("/dev/log"); pipe("/proc/kmsg"); udp(); tcp(); internal(); };
 log { source(src); destination(d_mysql); };
popis ukazky
  • prvni radek
    urcuje kam se bude logovat, data se zapisou do pipe (pajpy/pipy) /var/log/mysql.pipe, uprav to podle sablony(jako sql insert), a spust program ktery zapise obsah pipy do mysql
  • druhy radek
    urci odkud se budou brat logy
  • treti radek
    urci co se ma kam logovat, je mozne pridat jeste filtr a tedy dulezite info posilat na mail/sms. Filtr se da psat jako regularni vyraz(vypocetne narocnejsi)
Nutno zabezpecit
  • bezici mysql server : uprava /etc/init.d/syslog-ng do start sekce pridat start mysql(pro jistotu)
[editovat]

Skripty/konfigurace syslog-ng pro přeposílání kritických zpráv administrátorům příslušných lokalit

staci upravit configuracni soubor syslog-ng. do logovaci sekce pridat filter

syslog-ng faq
http://www.campin.net/syslog-ng/faq.html
http://sial.org/howto/logging/syslog-ng/
CESKY http://www.abclinuxu.cz/blog/dw/2007/7/25/187781
ukazka konfiguraku
http://www.campin.net/syslog-ng.conf

Bude doplněno.

[editovat]

Konfigurace lokálních proxy syslog-ng pro přeposílání zpráv na hlavní syslog server lokality

Bude doplněno.

[editovat]

Logování v PHP skriptech

Pro logování a debug ve skriptech PHP je rovněž vytvořena sada funkcí. Jsou uloženy v souboru vl-debug.php.

Na začátku každého php skriptu, kde budeme využívat logování, načteme skript vl-debug.php.

K otestování návratové hodnoty uživatelské funkce pak použijeme funkci LOG_UNEXPECTED_USR_ERROR(navratova_hodnota,__LINE__); Narozdíl od stejnojmenné funkce v C, je zde nutné uvést číslo řádku - pomocí předdefinované konstanty __LINE__.

Jakákoliv chyba, která se ve skriptu vyskytne je automaticky odchycena a zpracována (uložena do logu) funkcí LOG_UNEXPECTED_SYS_ERROR. Tu tedy není nutné explicitně volat.

Pro logování různých úrovní "chyb" použijeme funkci VLLOG($uroven,__LINE__,"textova zprava"). Ta má oproti verzi v C ještě navíc parametr __LINE__.

Pro pomocná debug hlášení slouží DBGPRINTF($formatovaci_retezec,[$dalsi_argumenty,[....]]). Vyžaduje argumenty stejným způsobem jako např. funkce printf()

Debug výpis se dá vypnout/zapnout podle nastavení konstanty VDEBUG v souboru vl-debug-const.php. V tomto souboru se nastavuje také úroveň logování.

Příklad použití je v souboru vl-debug-test.php.

[editovat]

Logování ve shell skriptech ( bash )

Pro záznam hlášení na Syslog ze shell skriptů používáme funkci VLLOG z COMMON/src/vl-debug.sh. Logováni musí být nejprve inicializováno funkcí INITLOGGING FAC_xxx (nastavení implicitní facility).

Syntaxe VLLOG je 

VLLOG {emerg|alert|crit|err|info|notice|warning|debug } TEXT

V levelu debug se automaticky do zprávy zaloguje i jméno skriptu a aktuální řádek.

Pro realizaci se používá systémového programu logger.

Úrovně, které se mají pro jednotlivé facility logovat, jsou nastaveny v souboru /etc/virtlab/shell-logging.conf. Syntaxe viz příklad.

Příklad použití viz vl-debug-test.sh.

Není-li zavoláno INITLOGGING a promenna VGLLOG_FACILITY není nastavena (zděděna), nastavuje se na VLLOG_UNDEFINED a zprávy se logují s facility local8.

[editovat]

Tracing shell skriptů

  • Zapnutí výpisu provedených příkazů: do #!/bin/bash na prvním řádku skriptu přidat -x
  • Zapnutí výpisu čísel řádků: před spuštěním skriptu export PS4='line $LINENO: '


Další viz http://www.unix.org.ua/orelly/unix/ksh/ch09_01.htm

[editovat]

Logování v Perl skriptech

viz vl-debug.pl

[editovat]

Ukladani zaznamu, ohlasovani chyb e-mailem

Od loggingu ocekavame toto:

  • Log hlaseni generovana komponentami urcite lokality by se mely automaticky zaznamenavat do souboru syslogu teto lokality. A to vcetne identifikace facility a debugLevelu
  • Log hlaseni generovana komponentami urcite lokality od urciteho nastaveneho debugLevelu vyse by se mely take kopirovat na emailovu adresu prirazenou lokalite pro "urgentni" zpravy. Ty se budou preposilat na SMS, takze by mely byt formatovany tak, aby clovek na mobilu z toho neco videl. Je nutne osetrit pripad, aby se od jedne chyby nevysypala zaplava SMS.
  • Pokud se v textu zpravy objevi >>JMENOLOKALITY<<, preposle se zprava jeste na emailovou adresu spravce teto lokality (cili dalsi konfigurak). Jedna se o situace, kdy se v lokalite X stane neco, co se tyka lokality JMENOLOKALITY.

Jinak potrebujeme, abychom byli schopni snadno sledovat sledy akci, ktere se v ramci jedne transakce deji na ruznych komponentach. To se nam bude velmi spatne delat, pokud ten logging bude rozhazeny do mnoha souboru nebo nekde v MySQL. Osobne soudim, ze nejlepe se veci hledaji GREPem. Proto v prvni fazi navrhuji sypat vsechno do jednoho textoveho logu a samozrejme u kazde zpravy zapisovat facility i debugLevel. Paralelne s tim mozno do MySQL a nahodit pro vzdalene prohlizeni PHPMyEdit.

V mysql logovat do 1 tabulky, a v ni udrzovat jen poslednich (treba) 7 dni, v archivni tabulce treba posledni mesic.

[editovat]

Ohlasovani chyb e-mailem

Pro logování jednotlivých komponent se používá programu syslog-ng. Tento program je velice flexibilní a umožňuje rozdělovat jednotlivé stupně závažnosti (priority) zpráv a zdroje zpráv (facility) do různých textových souborů. Pro projekt Virtlab je potřeba aby níže specifikované zpravy byly doručeny na email správců Virtlab-u a aby byl vložen záznam o chybě do systému pro zprávu chyb (VirtIS) . Zprávy, o které se budeme zajímat, jsou určeny úrovní závažnosti (priority) a tato závažnost je z rozsahu "crit".."emerg".

Konfigurační soubor syslog-ng má standardní umístění "/etc/syslog-ng/syslog-ng.conf". V tomto souboru je třeba nastavit aby syslog-ng požadované zprávy dále zpracovával způsobem, který specifikujeme. Nastavení programu syslog-ng se skládá ze tří částí.

V první části je třeba specifikovat "filtr" tedy specifikovat zprávy, o které máme zájem. Pro specifikaci filtru je potřeba vytvořit novou sekci "filter" a tato sekce je pojmenována "f_na_email". Ve filtru určíme priority zpráv, které se mají propustit. Příkazem "level( crit .. emerg );". Tyto priority se budou dále zpracovávat. Sekci "filter f_na_email" je třeba ukončit.

Dále je třeba vytvořit sekci ktera specifikuje kam se budou zaznamenané (zalogované) informace ukládat. Sekce typu "destination". Pojmenování sekce je "d_na_email". Standardní možnost je ukládat tyto informace do souboru a ten číst. Toto je nepraktické z důvodu náročnosti na software, který by měl číst takto vytvořený soubor. Proto je použita možnost ukládat informace (záznamy) do fifo souboru (souborová routa) a spustit obslužný software, který bude z fifo souboru záznamy vybírat.

Poslední sekce propojí výše popsané sekce. Výsledná konfigurace bude následující. Ze všech záznamu v syslog-ng vyber ty které mají prioritu v rozmezí "crit" a "emerg". Tyto záznamy vlož do fifo souboru. Při spuštění syslog-ng spusť program mailsender2.sh, který bude vybírat záznamy z fifo souboru a bude je dále zpracovávat.

Další část odesílání záznamu na email a do systému pro zprávu chyb (bugtracking systém) je program mailsender2.sh, ktery je umístěný v adresáři /opt/virtlab/service/mailsender/. Tento program vybírá logovací záznamy z fifo souboru (kam je ukládá syslog-ng) a připraví je do souboru "aktualni-email", který se pravidelně odesílá programem "email-it".

Program "email-it" zpracovává soubor "aktualni-email" a v případě, že existuje jej zabalí spolu s kopií "syslog" souboru do archivu a tento archiv posle elektronickou poštou na definovány email. Dále založí v bugtracking systému (systém pro zprávu chyb) novy záznam pro chybu, kde rovněž přiloží výše zmíněný zabalený soubor. Tento program je spouštěn pomocí programu "cron" pravidelně co hodinu. Tímto způsobem je zajištěna agregace zpráv a maximálně jednou za hodinu se vytvoří záznam chyby do bugtracking systému a odešle se email o chybě.


konfigurace syslog-ng potrebna pro odesilani emailu 

destination d_na_email {
   #format
   #Dec 11 13:02:15 ostrava ostrava#cons-server[20942]: CRIT [src/server.c:140] : Cannot read value from file [/tmp/appletchecker13451696420942]
   #$YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC $HOST $PROGRAM $PRIORITY $MSG
   program( "/opt/virtlab/service/mailsender/mailsender2.sh" ); pipe( "/opt/virtlab/service/mailsender/mail.fifo" template( "$PRIORITY $YEAR-$MONTH-$DAY $HOUR:$MIN:$SEC $HOST $PROGRAM $PRIORITY $MSG\n" ) );
};
filter f_na_email {
   level( crit .. emerg );
};
log {
       source(s_all);
       filter(f_na_email);
       destination(d_na_email);
};
  • syslog-ng posila zpravy do souborove roury jmenem /opt/virtlab/service/mailsender/mail.fifo
  • dale je potreba soubor mailsender2.sh ktery je ulozeny /opt/virtlab/service/mailsender/mailsender2.sh
  • tento soubor presune zpravu ze souborove roury do normalniho souboru ktery je jednou za hodinu odeslan na email
  • odesilani jednou za hodinu zajistuje cron ktery spusti skript /opt/virtlab/service/mailsender/email-it
  • na ktery email se ma odesilat je definovano v email-it skriptu
Citováno z „http://infra2.cs.vsb.cz/vl-wiki/index.php/Virtlab:LoggingDebugging“
Osobní nástroje