Programowanie średnio-zaawansowane #22: loggery

Słowo logowanie pewnie kojarzy Ci się z logowaniem się przez jakieś okienko do aplikacji. Tymczasem możesz też logować jakieś dane podczas pisania swojego kodu. Po co wykonywać taką czynność? Podczas tego kursu wielokrotnie używałem metody println do wyświetlania zawartości zmiennych, co na pewno bardzo ułatwiło Ci zrozumienie napisanego przeze mnie kodu. Teraz wyobraź sobie, że pracujesz z systemem, który zawiera miliony klas. Dostajesz informację od użytkownika tego systemu, że coś nie działa poprawnie (np. nie może zapisać danych po kliknięciu na button ‚zapisz’ w jakimś formularzu). W jaki sposób szybko zdiagnozujesz co jest nie tak? Jak zawsze w programowaniu, jest kilka sposobów, aby rozwiązać ten problem. Jednym z nich jest stosowanie jakiegoś mechanizmu do wyświetlania danych, przetwarzanych wewnątrz aplikacji. Najbardziej prymitywnym sposobem jest używanie przeze mnie, znanego Ci już z poprzednich lekcji, System.out.println(). Niestety ten sposób, o ile dobrze sprawdza się w prostych programach ćwiczebnych, to nie działa odpowiednio w komercyjnym programowaniu. Powodów, dla których nie używa się System.out.println() w dużych systemach jest wiele, ale najważniejszym jest fakt, iż System.out nie jest synchronizowany. Oznacza to, że nie działa prawidłowo w wielowątkowym środowisku (czyli praktycznie w każdej aplikacji, która nie ogranicza się tylko do prostego „maina”.

Lepszym sposobem do takiego wyświetlania danych diagnostycznych Twojej aplikacji, jest korzystanie z dedykowanego loggera. Logger to po prostu komponent w Javie, który zajmuje się bardziej zaawansowanym logowaniem kodu. W tym wpisie opiszę logowanie za pomocą loggera, dostępnego w standardzie Javy. W praktycznie będziesz raczej używać dedykowanego frameworku zajmującego się logowanie jak np. Log4J. W praktyce jednak każdy z nich używa się podobnie, więc lepiej dla Ciebie, wpierw nauczyć się standardowego loggery w Javie, a później, gdy będziesz już umieć dołączać dodatkowego biblioteki do swojego projektu, korzystać z innych rozwiązań.

Załóżmy, że chcę wyświetlić na konsoli „Hello world!”. Korzystając z System.out wyglądałoby to tak:

public class LoggerUsage {
	public static void main(String[] args) {
		System.out.println("Hello world!");
	}
}

Korzystając z loggera ten sam kod będzie wglądał w ten sposób:

public class LoggerUsage {
	public static void main(String[] args) {
		Logger logger = Logger.getLogger(LoggerUsage.class.getName());
		logger.log(Level.INFO, "Hello world!");
	}
}

Pierwsza linijka do definicja loggera, który chcesz używać. Jedynym bardziej skomplikowanym fragmentem jest metoda getLogger, która za parametr przyjmuje nazwę, po który będzie rozpoznawać swój logger. Jest to o tyle istotne, że w swojej aplikacji możesz mieć wiele loggerów, a także tworzyć bardziej skomplikowane mechanizmy zarządzania nimi (np. niektóre powyłączać, jeśli zajdzie potrzeba). Z reguły w tym parametrze wpisujesz nazwę swojej klasy. Dużo ładniej jednak jest zamiast tego skorzystać z obiektu class*, która za pomocą metody getName wygeneruje Ci zawsze aktualną nazwę Twojej klasy (wraz z pakietem, w którym jest zawarta).

Następnie możesz już skorzystać ze swojego loggera i wyświetlić „Hello world!” korzystając z metody log. Przyjmuje ona dwa argumenty: poziom logowanie wyrażony w formie typu wyliczeniowego oraz jakiś konkretny tekst. Efekt na konsoli powinien być taki:

maj 28, 2020 10:35:57 AM advanced.logger.LoggerUsage main
INFO: Hello world!

Pierwsza linijka jest to standardowy format loggera i zawiera: aktualną datę oraz nazwę pakietu z klasą i metody, z której został wywołany. W drugiej linijce oprócz napisu „Hello world!” przed dwukropkiem wyświetlony został poziom logowania, który został użyty (w tym przypadku info).

Logger zaimplementowany w JDK posiada kilka poziomów w swojej hierarchi:

  • SEVERE (najwyższy poziom)
  • WARNING
  • INFO
  • CONFIG
  • FINE (domyślny)
  • FINER
  • FINEST

Poziomy logowania służą do gdy chcesz w łatwy sposób przesłonić jakieś logi. Dobrym przykładem są logi, które wyświetlają informacje o poważnych błędach w systemie i logi diagnostyczne. W momencie, gdy potrzebujesz szukać poważnego błędu, a liczba linii wyświetlonych na konsoli jest w tysiącach, dużo łatwiej by było zamiast przeglądać je wszystkie, wyświetlić tylko te najbardziej istotne. Po to właśnie istnieją poziomy logowania.

Ogólnie przyjęta zasada mówi, że poziom SEVERE powinien być użyty do logowania błędów. WARNING używaj raczej do wyświetlania informacji o wyjątkach. INFO to dodatkowe informacje dla programisty. Natomiast niższe poziomy powinne być używane tylko, gdy chcesz debuggować swój kod.

Kod logger.log(Level.INFO, „Hello world!”); możesz napisać krócej używając dedykowanej funkcji info, która już ma w sobie ustawiony odpowiedni poziom. Analogicznie podobne funkcje istnieją dla innych poziomów.

logger.severe("Hello world!");
logger.warning("Hello world!");
logger.info("Hello world!");
logger.config("Hello world!");
logger.fine("Hello world!");
logger.finer("Hello world!");
logger.finest("Hello world!");

Jeśli chciałbyś zmienić poziom logowania z FINE na jakiś inny, to możesz to zrobić używając metody setLevel.

logger.setLevel(Level.INFO);

Teraz wyświetlą się tylko logi ustawione na poziomie INFO lub wyższym:

maj 28, 2020 10:58:34 AM advanced.logger.LoggerUsage main
SEVERE: Hello world!
maj 28, 2020 10:58:34 AM advanced.logger.LoggerUsage main
WARNING: Hello world!
maj 28, 2020 10:58:34 AM advanced.logger.LoggerUsage main
INFO: Hello world!

Jeśli chcesz dodatkowo sprawić, aby konkretny log wyświetlał się tylko i wyłącznie przy właściwym poziomie logowania, skorzystaj z metody isLoggable:

if (logger.isLoggable(Level.INFO)) {
	logger.info(LoggerUsage.class.getSimpleName());
}

Kolejną przydatną funkcją logów są handlery. Dają one możliwość przechwytywanie logów i zapisywanie ich na różnych strumieniach wyjścia. Domyślnym handlerem używanym w logach jest ConsoleHandler, który umożliwia wyświetlenie danych na ekran. Drugim równie używanym jest FileHandler i jego zadaniem jest zapisywanie danych do pliku. Co ciekawe za pomocą różnych formaterów, te same dane mogą mieć inny wygląd w zależności, który handler użyjesz. To kolejna przydatna funkcja loggerów.

FileHandler handler = new FileHandler("myapp-log.txt");
logger.addHandler(handler);
logger.info("Teraz logi trafia tez do pliku");

Jeśli spojrzysz w swój katalog projektowy, to znajdziesz tam nowo utworzony plik o nazwie myapp-log.txt. W nim zawarte będą Twoje logi.

Teraz pokażę Ci jak napisać swój formater, który zastąpi ten domyślny. Użyję go właśnie do logowanie danych do pliku.

public class MyFormatter extends Formatter {

	@Override
	public String format(LogRecord record) {
		return record.getSourceClassName() + ", " + record.getSourceMethodName() + ", " 
				 + record.getMessage() + ", " + LocalDate.now() + "\n";
	}

}

Stworzyłem prostą klasę, która rozszerza klasą Formatter. Zawarta w niej metoda format zwraca nową strukturę logów. W moim przypadku stwierdziłem, że chcę, aby każda linijka zawierała: nazwę klasy (getSourceClassName()), w której się znajduje, później po przecinku nazwę metody (getSourceMethodName()), następnie wiadomość do zapisania i na końcu aktualną datę. Pamiętaj też o znaczniku końca linii („\n”), bo inaczej cały log będzie „zlepiony” w jednej linii. 😉

Teraz mój kod z użyciem formatera będzie wyglądał tak:

FileHandler handler = new FileHandler("myapp-log.txt");
handler.setFormatter(new MyFormatter());
logger.addHandler(handler);
logger.info("Teraz logi trafia tez do pliku");

Teraz do pliku trafi mój sformatowany log:

advanced.logger.LoggerUsage, main, Teraz logi trafia tez do pliku, 2020-05-28

Logi bardzo często stosuje się w sekcji catch, podczas łapania wyjątków. W poniższym przykładzie wywołam NullpointerException i zaloguję go korzystając z trójargumentowej wersji metody log.

Object object = null;
		
try {
	object.toString();
} catch(Exception e) {
	logger.log(Level.WARNING, e.getMessage(), e);
}

W tym przypadku metoda log posiada argumenty: pioziom logowania, wiadomość wyświetlana w logu (możesz skorzystać z gotowej wersji pobierając ją z wyjątku z pomocą getMessage) i na końcu wyjątek, który łapiesz.

Na konsoli powinno pokazać się:

maj 28, 2020 11:15:07 AM advanced.logger.LoggerUsage main
WARNING: null
java.lang.NullPointerException
	at advanced.logger.LoggerUsage.main(LoggerUsage.java:37)

* Nie przejmuj się, jeśli nie rozumiesz koncepcji obiektu class. Jest to po prostu automatycznie stworzony przez Javę obiekt, na podstawie klasy Class, która zawiera kilka pomocniczych metod, przydatnych czasem przy implementacji.

Dodaj komentarz