7 - Logování a testování

• pro vyučující: 07

Zdrojové kódy pro práci na cvičení ke stažení zde.

Jak takové logování vypadá?

Jistě znáte a používáte System.out/err.print(). To umožňuje samozřejmě vypisovat libovolné hlášky v libovolných místech, ale neumožňuje efektivně vypínat či přepínat způsob výpisu, přesměrovávat výpis do více než dvou (out, err) výstupů, nebo nastavovat úroveň důležitosti.

Existuje více logovacích frameworků (můžete si napsat i svůj), ale pro jednoduchost zůstaneme u tohoto defaultního (java.util.logging), který poskytuje vše, co zatím potřebujeme.

Vytvoříme si statický logger v naší třídě (podle které dostane i jméno - je to konvence)

private static final Logger LOG = Logger.getLogger(<your-class>.class.getName());

LOG.log(<level>,<msg>,[<object>])
LOG.severe/warning/info/config/fine/finer/finest(<msg>)

Na obrázku výše vidíme základní rozlišení logovacího frameworku java.util.logging. Je třeba odlišovat několik typů:

• Level - určuje významnost zprávy
• Logger - aplikace skrze Logger zprávy vytváří a posílá do Handlerů
• Handler - přijímá zprávy a zpracovává je (tiskne na konzoli, do souboru, do paměti,…)
• Filter - umožňuje omezit množství zpráv (jak odesílaných z Loggeru, tak zpracovávaných Handlerem)
• Formatter - umožňuje formátovat zprávy (nebudeme se jím zabývat)

Ideálně (doporučuje se) má každá třída svůj logger. Každý nový logger používá defaultně handlery svého rodiče (odvozeného právě díky konvenci v pojmenovávání podle balíčků - tříd). To lze nastavit pomocí LOG.setUseParentHandlers(<boolean>);.

Vždy existuje kořenový (root) logger, který má jméno “” (prázdný string), ke kterému se dostaneme pomocí Logger.getLogger(“”);. Tento “root” logger defaultně vypisuje na System.err. Jakýkoli další vytvořený logger tedy defaultně přebírá handlery rodiče, kterými se rekurzivně dostaneme až k root loggeru, a tudíž se defaultně vypisuje na System.err, ikdyž jsme žádný handler nenastavovali.

Každý logger má nastavený svůj Level (defaultně je to Level.INFO), který označuje, že se zprávami, které mají význam menší než INFO (tzn. CONFIG, FINE, FINER, FINEST) se vůbec neobtěžuje (není tak úplně pravda - bude objasněno později) a nepošle je dále.

Stejně tak i handler má nastavený svůj Level (defaultně je to Level.INFO), který funguje stejně jako u loggerů. Obojí se dá nastavit pomocí <logger/handler>.setLevel(<level>):

• Level.ALL znamená výpis všech zpráv
• Level.OFF znamená výpis žádných zpráv

Nakonec, pokud chceme i jiný výstup z loggeru než přes System.err, musíme vytvořit a přiřadit loggeru jiný handler. Pokud používáme (což bychom měli) jiný logger než root (“”), můžeme se zbavit defaultního přesměrovávání na System.err pomocí

LOG.setUseParentHandlers(false);

Nyní můžemee experimentovat s vlastními handlery:

• Pro výstup na System.err:

LOG.addHandler(new ConsoleHandler()) //pozn.: ConsoleHandler využívá System.err a nejde změnit

• Pro výstup na System.out:

Handler stdout = new StreamHandler(System.out, new SimpleFormatter());
LOG.addHandler(stdout);

public class ConsoleHandler extends StreamHandler {
...
@Override
public void publish(LogRecord record) {
   super.publish(record);
   flush();
}

Handler stdout = new StreamHandler(System.out, new SimpleFormatter()) {
    @Override
    public void publish(LogRecord record) {
        super.publish(record);
        flush();
    }
};

• Pro výstup do souboru:

LOG.addhandler(new FileHandler(<filename.log>));

Každý logger může mít více handlerů a naopak.

Kromě logovacího frameworku v Java JDK existují ještě další. Za zmínku stojí například Log4j anebo SLF4J, což je společný interface (wrapper) pro více logovacích frameworků (včetně Log4j). SLF4J má zároveň nativní implementaci Logback. Který z nich použijete je pak na Vás, každý má nějaké výhody/nevýhody.

Zkuste si vytvořit nový soubor JFrame Form. Po jeho spuštění se objeví prázdný JFrame. Aplikace nic nedělá a jen čeká na zavření okna. Opravdu se však nic neděje?

• Nápověda č.1: Prozkoumejte root logger, třeba ho využívají i jiné části aplikace (GUI)
• Nápověda č.2: K handleru, který používá root loger se dostanete např. pomocí Logger.getLogger(“”).getHandlers()[0]
• Nápověda č.3: Nepoužívejte Level.ALL, stačí Level.FINE

Stáhněte a otevřete si ukázkový (dobře se na něm ukazuje, ne že by byl dokonalý) projekt BouncingBall. Když pominete plynulost animace, tak po chvíli hraní se může stát, že míček zapadne pod spodní okraj obrazovky. Aplikace však stále běží. Ale co se děje s míčkem? Postupuje dále do hlubin? Odráží se pořád od zdí? Co když se mu přechodem do jiné části obrátila i gravitace? A co na to Jan Tleskač?

Zkuste to odhalit pomocí logovaných zpráv. Rozlište různé typy zpráv pomocí levelu.

• Pozice míčku
• Odraz od zdi
• Změna stavu aplikace (po kliknutí na tlačítka)
• Tip: ve výpisech je lépe vidět, když má zem souřadnice y=0 (například obrácením gravitace nebo lze upravit samotný výpis)

Testování si ukážeme na programu kalkulačky—třída Calculator.

Máme k dispozici implementaci programu a potřebujeme ji otestovat. Aby nám testovací konstrukce nepřekážela v implementaci, je výhodné ji mít někde separátně - jako např. jUnit test class. V Mavenu se testovací třídy umisťují do složky src/test.

Minimální testovací třída může vypadat následovně:

import org.junit.*;
import static org.junit.Assert.*;
public class CalculatorTest {
    @Test
    public void testIt() {
        Calculator c = new Calculator();
        int result = c.add(12, 5);
        assertTrue("12 + 5 should equals 17, not " + result, result == 17);
    }
}

Vyzkoušejte si, co se stane, když funkce add bude vracet jiný než očekávaný výsledek.

Porovnávacích funkcí je spousta (viz javadoc):

• assertTrue
• assertFalse
• assertEquals
• assertArrayEquals
• assertNull
• assertNotNull
• assertSame
• assertNotSame

Testovací metoda může testovat i správné házení výjimek. Stačí do anotace metody připsat třídu očekávané výjimky. Můžete například otestovat dělení nulou zápisem:

@Test(expected = ArithmeticException.class)
public void testDivisionByZero() {
    new Calculator().divide(5, 0);
}

Lze i testovat dobu trvání metod. Například pokud dokážeme odhadnout dobu výpočtu, můžeme nastavit timeout, po jehož překročení skončí test chybou. Vhodné například pro detekci zacyklení programu. @Test(timeout = 100). V našem případě kalkulačky to může být použito například pro testování efektivity algoritmu funkce faktorial (rozdíl mezi iterativním a rekurzivním výpočtem).

Pokud testujete složitější třídu, kde je potřeba inicializovat data před testy, lze použít metody s anotacemi:

• @Before, @After - spustí se před a po každém testu (metodě s anotací @Test)
• @BeforeClass, @AfterClass - spustí se před prvním a po posledním testu

Dále existuje anotace:

• @Ignore - lze zapsat před @Test a tím tento test vypustit (vhodné např. když daná testovaná část programu není aktuálně v provozuschopném stavu)

Pokud je tělo testovací metody prázdné, pak test dopadne úspěšně. To znamená ale jen, že neobjevil chybu, ne že žádná chyba neexistuje. Správný test najde všechny případy, ve kterých dojde k chybě (funkce se chová jinak než se očekává) a skončí hláškou Failed; v ostatních případech (pokud je funkce bezchybná) skončí s hláškou Passed.