changed:
-
Logy (záznamníky, journaly, žurnály,...) využíváme ve dvou rovinách:

* při ladění programu
* při sledování činnosti hotového programu

Jak to obvykle chodí při ladění
====================

Znáte, to. Ladíte program a v kritických místech vkládáte nějaký ten ``print``, který
vypisuje obsah těžce zkoušené proměnné, nebo jen něco inteligentního jako "tady",
abychom viděli, kudy to běželo.

Když je kritické místo v pohodě váháme, zda onen ``print`` vyhodit, nebo jen
zakomentářovat. Co kdyby se ještě někdy hodil, že? A taky že při revizi kódu
se nám podobná hláška od minula skutečně někdy hodí.

Ale proč to všechno dělat složitě a chaoticky, když máme v Pythonu vestavěný modul *logging*.

Příklad na úvod
===============

::

    import logging
    logging.warning("Varovná hláška")


Po spuštění tohoto příkladu se vypíše::

 WARNING:root:Varovná hláška

A je to. Jak vidíme, logování může fungovat bez jakéhokoliv dalšího nastavování.
Výpisy vystupují na ``stderr``, což je obvykle konzole z níž program spustíme.

Základní nastavení
==================

Log, který vypisuje hlášky na konzoli ovšem není zpravidla to, co by nám stačilo. Navíc
formát řádky se nám taky nemusí líbit. Takže využijme možnosti konfigurace:
::

    import logging
    logging.basicConfig(
        filename="program.log",
        format="%(asctime)s %(levelname)-8s %(message)s",
        level=logging.INFO)
    logging.info("Nejaka informace")
    logging.warning("A nejake varovani")

Nyní se bude logovat do souboru s názvem *program.log*. Jeho obsah bude:
::

    2007-05-07 16:04:44,972 INFO     Nejaka informace
    2007-05-07 16:04:51,802 WARNING  A nejake varovani

To už vypadá lépe, že?

Trocha teorie
=============

Nechtěl jsem hned z počátku motat hlavu. To co jsme si ukázali jako návnada stačilo.
Není nutné tu opisovat dokumentaci ke standardní knihovně - tu každý ví, kde má; pod
polštářem.

Základním objektem modulu *logging* je objekt **Logger**. Jeho základní instance
se jmenuje *root* a je vytvořena automaticky hned po načtení modulu. Proto jsme
taky v prvním příkladu mohli hned logovat, a taky už víme, proč se ve výpisu jako
druhá položka objevilo to slovo "root".

Každý ``Logger`` se projevuje prostřednictvím objektů **Handler**. Množné číslo
je na místě - handlerů může mít jeden logger více. Pak se hlášky generované tímto
loggerem objevují na více místech současně (třeba na konzoli a v souboru).

Aby hlášky nějak vypadaly, o to se stará objekt **Formater**. Každý handler může
mít vlastní formát, takže když bychom si skutečně nechali vypisovat hlášky do
souboru a ještě na konzoli, budeme v souboru chtít mít datum a čas, zatímco na
konzoli by to asi byl tak nějak zbytečný údaj.

Protože ne vše musí být textový soubor, je tu ještě objekt **!LogRecord**,
který zajišťuje správně zformátování pro příslušný handler. Ten ale pracuje
automaticky na pozadí a my se o něj starat nemusíme.

Modul *logging* má pět vestavěných úrovní - konstant s odpovídající číselnou hodnotou:

=============   ===============
 jméno levelu   číselná hodnota
-------------   ---------------
  CRITICAL            50
  ERROR               40
  WARNING             30
  INFO                20
  DEBUG               10
=============   ===============

Každý *logger* má svoji nastavenou úroveň logování. Hlášky s nižší úrovní
se do logu nedostanou. Logger může svou úroveň změnit pomocí metody ``setLevel``.
Např::

    mylogger.setLevel(logging.INFO)
Nastaví úroveň logování pro logger "mylogger" na INFO.

Pro logování hlášek pak používáme metody loggeru s názvy, odpovídajícími příslušným
levelům: .debug('zpráva'), .info(... Krom toho máme k dispozici obecnou metodu ``log(level, 'zprava')``,
díky níž můžeme zprávu zalogovat s úrovní jakou chceme (třeba 36).

Dokumentace odhalí i další možnosti těchto metod.


Takže znovu prakticky
=====================

Po přečtení předchozí kapitoly a se spuštěným interpreterem Pythonu ve druhé ruce
bude následující příklad převzatý z originální dokumentace lahůdka. V tomto
příkladu vidíme, jak nastavit dva handlery s různými formáty výstupu. Jeden (základní)
jde do souboru, druhý s názvem *console* se vypisuje v konzoli. Taky vidíme
vytvoření dvou loggerů, které pracují s nastavenou konfigurací.
::

    import logging
    logging.basicConfig(level=logging.DEBUG,
        format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
        datefmt='%Y-%m-%d %H:%M:%S',
        filename='myapp.log',
        filemode='w')
    console = logging.StreamHandler()
    console.setLevel(logging.INFO)
    formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
    console.setFormatter(formatter)
    logging.getLogger('').addHandler(console)
    logging.info('Jackdaws love my big sphinx of quartz.')
    logger1 = logging.getLogger('myapp.area1')
    logger2 = logging.getLogger('myapp.area2')
    logger1.debug('Quick zephyrs blow, vexing daft Jim.')
    logger1.info('How quickly daft jumping zebras vex.')
    logger2.warning('Jail zesty vixen who grabbed pay from quack.')
    logger2.error('The five boxing wizards jump quickly.')

Na výstupu z konzole obdržíte::

    root        : INFO     Jackdaws love my big sphinx of quartz.
    myapp.area1 : INFO     How quickly daft jumping zebras vex.
    myapp.area2 : WARNING  Jail zesty vixen who grabbed pay from quack.
    myapp.area2 : ERROR    The five boxing wizards jump quickly.

A v logovacím souboru *myapp.log* bude tohle::

    2007-05-07 16:33:33 root         INFO     Jackdaws love my big sphinx of quartz.
    2007-05-07 16:33:33 myapp.area1  DEBUG    Quick zephyrs blow, vexing daft Jim.
    2007-05-07 16:33:33 myapp.area1  INFO     How quickly daft jumping zebras vex.
    2007-05-07 16:33:33 myapp.area2  WARNING  Jail zesty vixen who grabbed pay from quack.
    2007-05-07 16:33:33 myapp.area2  ERROR    The five boxing wizards jump quickly.

Příklad s více moduly
=====================

V praxi sestávají naše aplikace z více modulů. Tady je hlavní úlevou dovědět se,
že konfigurace loggeru se do importovaných modulů přenáší automaticky a my se
o to starat nemusíme.

Ukažme si to na příkladu. Základní konfiguraci loggeru jsem dal do samostatného
modulu *mylog.py*. Ten si každá aplikace může načíst hned na začátku (možnost
logovat chceme asi pořád, že?).

A pak tu máme ještě vymyšlený modul *mydbmod.py*, který předstírá otevírání databáze.
My ho tu máme ale hlavně proto, abychom ukázali, že konfigurace loggeru se opravdu
přenáší automaticky všude - do všech modulů importovaných po inicializaci loggeru.

**mylog.py**::

    import logging

    # jmeno souboru pro logovani:
    logfile = "prog.log"
    # nejnizsi logovana uroven:
    loglevel = logging.INFO

    def logstart():
        logging.basicConfig(
            filename=logfile,
            format="%(asctime)s %(levelname)-8s %(name)-10s %(message)s",
            level=loglevel)
        logging.info("Logovani zapnuto")

    def logstop():
        logging.info("Logovani ukonceno")
    
    logstart()

**prog.py**::

    import logging, mylog
    mylogprg = logging.getLogger('prog')
    mylogprg.info("Hlavni modul aplikace startuje...")

    import mydbmod

    class App:
        def __init__(self):
            mydbmod.opendb()

    if __name__ == '__main__':
        app = App()
        mylog.logstop()


**mydbmod.py**::

    import logging

    mylogdb = logging.getLogger('prog.dbmod')
    mylogdb.info('Zavadeni modulu mydbmod - start')
    mylogdb.setLevel(logging.DEBUG)

    # Tady je obsah modulu...
    def opendb():
        # neco co otevre databazi
        # ...
        mylogdb.debug('Databaze otevrena.')

    mylogdb.info('Zavadeni modulu mydbmod - hotovo.')


Závěrem
=======

Logování v Pythonu je významná pomůcka jak pro vývojáře, tak pro uživatele a administrátory.
Nemusíme nic vymýšlet. Logovací nástroje máme ve standardní knihovně. Další podrobnosti
hledejte v originální dokumentaci.

Zdraví Strýček Grumpa :o)

import logging
logging.warning("Varovná hláška")

WARNING:root:Varovná hláška

import logging
logging.basicConfig(
    filename="program.log",
    format="%(asctime)s %(levelname)-8s %(message)s",
    level=logging.INFO)
logging.info("Nejaka informace")
logging.warning("A nejake varovani")

2007-05-07 16:04:44,972 INFO     Nejaka informace
2007-05-07 16:04:51,802 WARNING  A nejake varovani

mylogger.setLevel(logging.INFO)

import logging
logging.basicConfig(level=logging.DEBUG,
    format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S',
    filename='myapp.log',
    filemode='w')
console = logging.StreamHandler()
console.setLevel(logging.INFO)
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
console.setFormatter(formatter)
logging.getLogger('').addHandler(console)
logging.info('Jackdaws love my big sphinx of quartz.')
logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')
logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')

root        : INFO     Jackdaws love my big sphinx of quartz.
myapp.area1 : INFO     How quickly daft jumping zebras vex.
myapp.area2 : WARNING  Jail zesty vixen who grabbed pay from quack.
myapp.area2 : ERROR    The five boxing wizards jump quickly.

2007-05-07 16:33:33 root         INFO     Jackdaws love my big sphinx of quartz.
2007-05-07 16:33:33 myapp.area1  DEBUG    Quick zephyrs blow, vexing daft Jim.
2007-05-07 16:33:33 myapp.area1  INFO     How quickly daft jumping zebras vex.
2007-05-07 16:33:33 myapp.area2  WARNING  Jail zesty vixen who grabbed pay from quack.
2007-05-07 16:33:33 myapp.area2  ERROR    The five boxing wizards jump quickly.

import logging

# jmeno souboru pro logovani:
logfile = "prog.log"
# nejnizsi logovana uroven:
loglevel = logging.INFO

def logstart():
    logging.basicConfig(
        filename=logfile,
        format="%(asctime)s %(levelname)-8s %(name)-10s %(message)s",
        level=loglevel)
    logging.info("Logovani zapnuto")

def logstop():
    logging.info("Logovani ukonceno")

logstart()

import logging, mylog
mylogprg = logging.getLogger('prog')
mylogprg.info("Hlavni modul aplikace startuje...")

import mydbmod

class App:
    def __init__(self):
        mydbmod.opendb()

if __name__ == '__main__':
    app = App()
    mylog.logstop()

import logging

mylogdb = logging.getLogger('prog.dbmod')
mylogdb.info('Zavadeni modulu mydbmod - start')
mylogdb.setLevel(logging.DEBUG)

# Tady je obsah modulu...
def opendb():
    # neco co otevre databazi
    # ...
    mylogdb.debug('Databaze otevrena.')

mylogdb.info('Zavadeni modulu mydbmod - hotovo.')