Warsztat.GDCompo!ProjektyMediaArtykułyQ&AForumOferty pracyPobieranie

Opisz napotkaną sytuację, a redakcja niezwłocznie znajdzie rozwiązanie!

wyślij anuluj

Logger

Uwaga! Tekst posiada 1 niepotwierdzonych zmian!

Tekst został importowany z Warsztatowych artykułów. Jego oryginalnym autorem jest TeMPOraL. Jeżeli został importowany poprawnie, usuń ten szablon!

"Dziennik pokładowy, data gwiezdna..." - tak zaczyna się prawie każdy odcinek popularnego na całym świecie serialu Star Trek. Jednak dziennik pokładowy to nie wymysł Sci-Fi, ale rzecz stosowana od wieków. Każdy rozsądny kapitan statku prowadzi dziennik pokładowy, w którym zapisuje ważne zdarzenia związane z pełnionym zadaniem - czy jest to polowanie na Czerwony Październik, czy na garść krewetek. Jeśli przydarzy się wypadek, dziennik jest najważniejszą po ludziach rzeczą do uratowania.

Dzienniki, zwane dalej logami, podobną rolę pełnią w informatyce. Wystarczy się rozejrzeć - systemy Unixowe intensywnie logują; Windows intensywnie loguje; wiele gier i programów (zwłaszcza tych profesjonalnych) także zapisuje logi. Niemniej okazuje się, że ten praktyczny zwyczaj jest pomijany przez wielu koderów. Celem niniejszego tekstu jest omówienie do czego służy logger, jak go pisać oraz jak się nim efektywnie posługiwać. W celu uściślenia używanego w tym artykule języka zaznaczam, że pojęcie 'logowanie' odnosi się do wysyłania wiadomości przez logger, a nie do autoryzacji w programie.

Logger jest bardzo praktycznym, acz strasznie niedocenianym narzędziem. Służy on przede wszystkim jako alternatywne medium komunikacji między aplikacją a użytkownikiem - często pojawiają się informacje warte zasygnalizowania, ale nie są one na tyle krytyczne by wyświetlać okno dialogowe na ekranie. Spektrum jego zastosowań jest na prawdę szerokie, wymienię tylko kilka przykładów:

  • Wykrywanie błędów logicznych w kodzie - Dzięki loggerowi możemy kontrolować poprawność działania kodu - czy odpowiednie funkcje wywoływane są w odpowiedniej kolejności, czy przekazywane parametry są poprawne i czy reakcja na nie przebiega prawidłowo. To wszystko możemy osiągnąć pisząc słownie jedną linię kodu.
  • Wykrywanie błędów wykonania - Nie wszystkie błędy da się wykryć w fazie kompilacji i testowania programu we własnym warsztacie. Czasami program działa dobrze u Ciebie i Twoich znajomych, ale pada na komputerze Twojego brata i to tylko we wtorki. Log z wykonania jest wtedy nieoceniony - dowiadujemy się na którym etapie pracy programu zdarzył się pad, i czym jest najprawdopodobniej spowodowany. Jest to na prawdę pomoc nieoceniona; pewnego razu chciałem przetestować swoją małą gierkę na komputerze w szkolnej (na szczęście w byłej szkole ;) ) pracowni - nawet nie skończyła się inicjalizować. Log powiedział wprost - komputer nie posiada karty dźwiękowej ^^.
  • Wykrywanie błędów u znajomych - Nasze programy często przechodzą testy w 'hazardous environment' - u naszych znajomych. Tam najczęściej wychodzą na jaw wszelkie błędy - gdy zmienia się środowisko, źle napisany kod zaczyna funkcjonować inaczej. Jednak pady zdarzają się też dużo po uznaniu konkretnej wersji za 'w miarę' bezbłędną. Wtedy właśnie bardzo przydaje się logger - zamiast wypytywać kolegę co robił gdy nasz program padł, możemy poprosić go o przesłanie nam loga z wykonania. Dobry log zazwyczaj daje bardziej konkretne i przydatne informacje na temat przyczyny błędu.
  • Zastępowanie zewnętrznych debuggerów - W typowych sytuacjach logger może z dużą skutecznością zastąpić debugger. Mówię tu o monitorowaniu wartości zmiennych - break point'ów raczej nie zastąpisz ;). Niemniej logger przydaje się szczególnie wtedy, gdy monitorowanie debuggerem jest utrudnione - np. w grze lub demie pracującym w trybie pełnoekranowym.
  • Upraszczanie pisania w początkowych okresach - Wiele projektów zaczyna się od bardzo szybkiego napisania renderera - musimy mieć jakiś sposób wyświetlania wyników działań poszczególnych modułów. Użycie loggera pozwala na opóźnienie pisania renderera do momentu, w którym jest to już na prawdę konieczne. Można skupić się na innych ważnych częściach rdzenia programu, a wyniki kierować do loga.
  • Wartość edukacyjna - To jest już odrębny czynnik. Sięgnijmy do wspomnień z okresu przed-koderskiego. Każdy z nas najpierw grał. Jednak później zaczęły przychodzić do głowy myśli: "jak to zmienić...", "jak to działa...", "może i ja tak potrafię?". Napewno czytelniku choć w minimalny sposób przeglądałeś logi gier, w które grałeś. Dobry log potrafi wiele powiedzieć o tym, jak zbudowana jest gra. Ta wiedza rozbudza zainteresowanie i sprowadza nowe pokolenie koderów. Czyż nie jest to szczytny cel? ;)

Jak wspomniałem, to tylko przykłady. Zastosowań loggera jest więcej, i prawdopodobnie każdy potrafi znaleść jakieś własne.

Co I Jak Pisać Do Loga

Co logować - to jest dość dobre pytanie. Przede wszystkim - żadna informacja nie jest zła. Warto logować zarówno komunikaty o błędach jak i powodzeniu. Jeśli mamy wprowadzony podział na podsystemy to po inicjalizacji każdego warto by ten fakt zaznaczyć w logu. To samo tyczy się deinicjalizacji. Jeśli ładujemy jakieś zewnętrzne dane, pochodzące na przykład z pliku, to ten fakt także powinien być zaznaczony. Przydzielanie nowych uchwytów do zasobów również jest informacją wartą zapisania. Logować warto zarówno wykonanie jakiejś czynności, jak i próbę jej wykonania - dzięki temu jesteśmy w stanie określić dokładnie gdzie i dlaczego program odmówił posłuszeństwa. W niektórych krytycznych pod względem poprawności funkcjach wypada odnotować wszelkie odchylenia przekazanych parametrów od normy.

Jednym słowem - warto logować wszystko, co ma realne znaczenie dla wykonywania się programu.

A jak logować? Przede wszystkim czytelnie - nie może być to log w stylu: "Init. FileLoad. OP123e. AT323.". Taki log jest ciężki do zrozumienia przez każdego kto go ogląda, więc nie ma praktycznej wartości. Oczywiście pewne tego typu wpisy są dopuszczalne w wersjach testowych - nie zawsze chce się wymyślać oryginalnego komunikatu dla 20 wpisów do loga w jednej funkcji, żeby sprawdzić czy wszystko działa. Nieczytelnych wpisów wypada jednak pozbyć się jak najszybciej. Czytelny przykład wpisu do loga może wyglądać następująco:

"Config File [engine.ini] parsed successfuly. Loaded 3 sections and 4 variables; 0 invalid entries were omitted"
"Settings Manager: Loaded Configuration File [engine.ini]"

Takie wpisy mówią dokładnie co się dzieje, kto to wykonuje, i są na tyle zrozumiałe, że w wypadku błędu i Twój nieznający się na programowaniu znajomy zrozumie mniej więcej co jest przyczyną usterki.

Najprostszy Logger

Najbardziej podstawowy logger składać się musi ze zwykłej funkcji zapisującej do pliku treść, którą chcemy zalogować. Taka funkcja musi mieć możliwość zapisu zawartości zmiennych, przynajmniej podstawowych typów - char, int, float i tekstu. Byłoby też bardzo pożądane, gdybyśmy mieli kontrolę nad loggerem - mogli go włączać i wyłączać w dowolnym momencie. W najprostszej wersji loggera użyjemy dwóch funkcji i zmiennej globalnej:

Deklaracje:
[kod; SimpleLog.h]

Implementacja:
[kod; SimpleLog.cpp]

Napisaliśmy właśnie bardzo prostego loggera - potrafi on tylko zapisywać komunikaty do odgórnie ustalonego w trakcie kompilacji pliku. Niemniej jest to logger mały, zgrabny, i do bardzo małych zastosowań wystarczający. Jego użycie jest bardzo proste - musimy najpierw go uaktywnić, wywołując:

SimpleLog::SetLogState(true);

Potem możemy dokonywać zapisu w sposób bardzo podobny do tego, do jakiego przyzwyczaja nas biblioteka stdio: SimpleLog::Log("troche tekstu; int: %d, float: %d, znak: %c, inny tekst: %s", 16, 128.5f, '?', "Kupujcie Warp ;)"); Ten logger po prostu otwiera plik i dopisuje na jego końcu nowe wiadomości, więc musimy jakoś oznaczyć gdzie zaczyna się log z nowego uruchomienia programu. Możesz sam zmodyfikować kod, żeby zerował plik przy włączaniu loga, lub żeby zapisywał na przykład datę jego uaktywnienia.

Nasz prosty logger może być oczywiście troszkę zoptymalizowany - funkcję SetLogState możemy zdefiniować w SimpleLog.h jako inline. Dodatkowo można wyciągnąć pLogFile z funkcji Log(), zrobić z tego zmienną globalną, i wykonywać otwieranie / zamykanie pliku w funkcji SetLogState(), zależnie czy parametr równy jest true, czy false.

Logger Nowszej Generacji

Opisany powyżej logger ma jednak swoje wady, które wychodzą na jaw przy większych projektach. Po pierwsze, plik do którego zapisujemy jest na stałe zapisany w kodzie. Do tego możemy używać w programie tylko jednego loggera - nie mamy możliwości tworzenia dzienników operujących na innych plikach. Sam interfejs może też nie odpowiadać wielu osobom - za bardzo przypomina C i bibliotekę stdio. Napiszmy więc lepszy logger, który rozwiąże powyższe problemy, będąc zarazem funkcjonalniejszy i wygodniejszy w obsłudze. Wypiszmy więc, jakie funkcje ma ten logger posiadać:

  • Powinno się dać tworzyć logi do różnych plików, których nazwy nie sa narzucone odgórnie, ale podawane. Znaczy to, że przy tworzeniu obiektu loga wybieramy pod jaki plik chcemy zapisywać, oraz możemy ten plik później zmienić.
  • Powinna istnieć możliwość otwarcia zamkniętego loga w trybie dopisywania. Możemy dzięki temu wybrać, czy chcemy zapisywać log od początku, usuwając starą zawartość pliku, czy też tylko dopisywać nowe wiadomości pod tym, co już w pliku było.
  • Plik powinien być otwierany jednokrotnie, a nie podczas każdego zapisu. Operacja otwierania pliku jest dość czasochłonna, więc dzięki temu unikniemy niepotrzebnego narzutu, który bardzo zagraża szybkości zapisu. Oprócz tego oddzielenie funkcji otwierających plik pozwala na stworzenie bardziej elastycznego loggera.
  • Interfejs zapisu powinien być jasny i funkcjonalny, najlepiej przypominający zapis używany w IOStream, z operatorami <<. Wielu programistów C++ jest przyzwyczajonych do operatorów << przy zapisie, dlatego warto taką metodę zapewnić - jest to ładne, miłe, przyjemne, i co ważniejsze rozszerzalne. Można samemu sobie przeładować taki operator dla własnych klas.
  • Ze względu na różne preferencje, logger powinien mieć też możliwość zapisu metodą z STDIO - przez tekst formatujący i zmienną liczbę argumentów. Wielu programistów preferuje interfejs stdio, więc i taką możliwość należy zapewnić. Oprócz tego interfejs stdio bywa niejednokrotnie bardziej wydajny, niż interfejs iostream, dlatego w krytycznych miejscach możemy zechcieć skorzystać z funkcji logującej o zmiennej liczbie argumentów.

Nowego loggera umieścimy w klasie - dzięki konstruktorowi i destruktorowi umożliwimy mu poprawne zamknięcie pliku na wypadek rzuconego wyjątku. Przejdźmy więc od razu do kodu:

[kod; CLog.h]

Fakt, troche to duze ;) Przejdzmy do implementacji:
[kod; CLog.cpp]

Używanie jest bardzo proste; tworzymy obiekt klasy CLog, otwieramy go z pomocą funkcji Open() lub Append() i możemy już zapisywać komunikaty. Na sam koniec wypadałoby zamknąć plik z użyciem funkcji Close(), ale jeśli o tym zapomnimy, to destruktor się tym za nas zajmie ;)

Trochę duży ten logger, ale swoje rozmiary rekompensuje nam dużą funkcjonalnością.

Wielowyjściowy Logger Z Filtrowaniem Priorytetów

Co prawda logger, który napisaliśmy przed chwilą to często nawet za dużo, jak na typową grę czy demo, ale jednak są pewne sytuacje, w których potrzebujemy jeszcze bardziej specjalistycznego narzędzia. Tyczy się to projektów takich jak silniki, czy choćby bardziej rozbudowane gry. W takich przypadkach logger jest zazwyczaj jednym z podsystemów; jednak taki podział elementów programu tworzy naturalną potrzebę stworzenia bardziej skomplikowanego loggera. Przecież każdy podsystem będzie chciał coś zapisać - czy to będzie Renderer, czy system wejścia, może Task Manager, albo AI. Do tego komunikaty mogą mieć różne znaczenie - co innego jest yet-anothet komunikat o sukcesie, a co innego fatalny błąd. Dlatego bardzo rozsądnym krokiem wydaje się wprowadzenie podziału komunikatów według ich znaczenia.

Zastanówmy się chwilę - podzieliliśmy w pewien sposób komunikaty, jednak po co nam to? Co można by z tym zrobić? Ciekawie byłoby na przykład mieć osobny plik na zapisywanie samych błędów. A może tak logowanie do pliku .html, z wyróżnieniem kolorów dla każdego rodzaju komunikatu? Albo jeszcze inaczej - konsolka windows NT, także kolorowana wedle wagi komunikatu. To nas wprowadza w temat loggera o wielu wyjściach.

Pomyślmy chwilę nad pojęciem wyjścia. Typowym wyjściem dla loggera jest plik tekstowy. Mniej typowym może być konsola Dos/NT, dziennik systemu operacyjnego, plik HTML czy RTF. Wszystkie te wyjścia mają wspólne cechy - za ich pomocą wyprowadzamy komunikat. Jeśli do wielowyjściowego loggera dołączymy koncepcję priorytetów wiadomości to możemy pozwolić wyjściom na filtrowanie określonych komunikatów - zapisywać na przykład tylko komunikaty o błędach, etc. Informując wyjście o typie przesyłanej wiadomości pozwalamy na użycie kolorów i innych dekoracji do zwiększenia czytelności tekstu.

Zidentyfikujmy więc podstawowe cechy nowego loggera:

  • Podział na główną klasę loggera i wyjścia. Podstawowa klasa wyjścia będzie klasą czysto wirtualną.
  • Obsługa filtrowania wiadomości dla wyjścia po stronie loggera.
  • Wiadomości opatrzone są odpowiednim priorytetem.
  • Logger obsługuje swobodne dodawanie i usuwanie wyjść, oraz zapis za pomocą zarówno funkcji a-la stdio, jak i operatorów << a-la iostream.

[Czytelniku, możesz zapoznać się teraz z plikami MOL.h, MOL.cpp, oraz ConsoleLogOutput.h/.cpp i TextLogOutput.h/.cpp]

W kodzie dołączonym do artykułu znajduje się zaimplementowany logger wielowyjściowy. Najważniejsze, co trzeba o nim powiedzieć, to sposób funkcjonowania operatorów <<. Otóż na początku każdej wiadomości należy wstawić manipulator LogPriority, a wiadomość zakończyć manipulatorem FlushLog. Gdybyśmy nie zflushowali loggera przed ponownym użyciem LogPriority, to stara wiadomość zmienila priorytet.

W kodzie znajduje się też implementacja wyjścia dla pliku tekstowego i konsoli Windows NT / MS-DOS. Obie używają funkcji WinAPI do wypisywania komunikatów. Przy wyjściach i priorytetach bardzo ważna jest opcja filtrowania - tworząc filter używamy wartości priorytetów, sumując je operatorem '|' (bitowej sumy). Wartości, które użyjemy będą tymi, które wyjście będzie przyjmować.

Napisane w tej implementacji wyjście do pliku tekstowego automatycznie usuwa starą zawartość pliku przed pierwszym zapisem. To zachowanie można oczywiście zmienić. Warty zasygnalizowania jest fakt, że wyjścia stanowią samodzielną jednostkę funkcjonalną, i mogą być używane bez loggera.

Użyte priorytety są oczywiście priorytetami przykładowymi - w różnych projektach mogą zajść różne potrzeby - np. można priorytetami sygnalizować nie tylko typ wiadomości, ale i podsystem który je wysyła.

Trochę Na Temat Wydajności

Warto rozważyć jak używanie loggera wpłynie na ogólną wydajność programu. Problemy są dwa - rozmiar kodu wynikowego i szybkość wykonania. W przypadku tego pierwszego znaczenie ma zwiększenie się ilości stałych tekstowych w kodzie. Im więcej logujemy, tym więcej tekstu kompilator musi upchnąć w programie. Nie jest to szczególny problem; w ekstremalnych przypadkach kod może wzrosnąć o kilka kilobajtów, jednak gdy rozmiar ma znaczenie (np. w 64kb Compo ;) ) to wypadałoby o tym pamiętać.

Wpływ loggera na szybkość wykonania zależy od tego, jak go wykorzystujemy. Przede wszystkim nie należy się bać logów pochodzących z pętli głównej, ale należy stanowczo unikać wypisywania komunikatu co 2-3 klatki w kodzie wersji ostatecznej - po kilku minutach zabawy rozmiar logu zacznie być liczony w megabajtach i wszelkie korzyści z tego narzędzia zanikną - wyobraź sobie ile to jest 1MB tekstu. W przypadku loggerów o wielu wyjściach uważać trzeba na wyjście na konsolę MS-DOS/NT Console - samo jej pokazanie spowalnia program, a wypisywanie na nią jest zabójstwem dla framerate. Żeby nie było, że rzucam ogólnikami - przy testowaniu task managera silnik z włączoną konsolą DOS/NT wyrabiał mi 100 FPS. Po jej zminimalizowaniu framerate zwiększył się do 1000 FPS, a po całkowitym wykomentarzowaniu z kodu - do 5000 FPS. Dlatego wyjścia konsolowego należy używać w trybie testowym (np. parametr -d podany jako argument do wykonania programu) - wtedy, gdy korzyści z oglądania loga w real-time przewyższają straty na liczbie FPS.

Modyfikacje

Oczywiście przedstawione tu koncepcje są tylko przykładowe; każdy projekt wymaga indywidualnego podejścia do sprawy. Czasem warto zrobić z loggera singleton, żeby pozbyć się wad używania zmiennych globalnych. Innym razem potrzebne może być przerobienie loggera na interfejs dla zapewnienia bezpieczeństwa przenośności kodu między platformami. Warto także rozważyć dopisywanie aktualnego czasu przed każdym wpisem do loga - taka informacja może się przydać przy debugowaniu kodu.

Jedną z ciekawszych opcji byłoby też zapisywanie plików o nazwie zawierającej datę i czas stworzenia lub kolejny numer. £atwiej jest wtedy zbierać dane z kilku uruchomień, i nie ma wtedy ryzyka że log zostanie omyłkowo skasowany jeśli włączymy nasz program ponownie. Wiele gier pracuje na tej zasadzie, chroniąc w szczególności log z błędami.

Niezależnie od wszystkiego, przedstawione w tym artykule pomysły powinny służyć jako wytyczne dla Ciebie, Czytelniku, na drodze do stworzenia Twojego Perfekcyjnego Loggera ;). Życzę Ci więc powodzenia, i dziękuję za czytanie ;)

TeMPOraL.

Załącznik: logger.zip

Tekst dodał:
Adam Sawicki
09.04.2006 19:46

Ostatnia edycja:
Adam Sawicki
09.04.2006 19:46
(+ 1 niepotwierdzonych zmian)

Kategorie:

Aby edytować tekst, musisz się zalogować.

# Edytuj Porównaj Czas Autor Rozmiar
#2 edytuj (poprz.) 21.05.2012 00:00 tanatos 18.88 KB (+495)
#1 edytuj (bież.) 09.04.2006 19:46 Adam Sawicki 18.39 KB
Zwykły
Do sprawdzenia
Do akceptacji
  • ~CyberKiełba 08 czerwca 2007 13:16
    Brawo! Bardzo profesjonalne podejście. Zagadnienie jest bezbłędne. Jestem pod wrażeniem profesjonalizmu.
  • Jacek Złydach (@TeMPOraL) 04 lipca 2007 23:24
    Dla zainteresowanych i nie tylko, kontynuację tematyki loggerów rozwijam pod poniższym adresem: http://temporal.pr0.pl/devblog/category/serie-tematyczne/loggery/
  • ~_MtZ_ 12 sierpnia 2007 22:53
    Jeśli chodzi o strumieniowe wyprowadzanie danych to nie łatwiej było użyć operatora<< sparametryzowanego?
  • losiu99 (@losiu99) 21 sierpnia 2008 22:33
    _MtZ_ - próbowałem, ale z szablonami jak to z szablonami - produkowało dla każdego .obj oddzielną wersję dla każdego użytego typu. Nie chciało mi się szukać innego rozwiązania, choć pewnie jakieś istnieje.
  • losiu99 (@losiu99) 22 sierpnia 2008 11:17
    tzn. nie ma problemu jak się tych szablonów używa w jednym projekcie. ¬le robi się dopiero jak np. używamy szablonu dla <int> w jakimś projekcie, i jednocześnie linkujemy z czymś innym, już skompilowanym, co też tą wersję <int> używało.
  • Napisz komentarz:
    Aby dodać swój komentarz, musisz się zalogować.
Licencja Creative Commons

Warsztat używa plików cookies. | Copyright © 2006-2017 Warsztat · Kontakt · Regulamin i polityka prywatności
build #ff080b4740 (Tue Mar 25 11:39:28 CET 2014)