We wpisie podziwiałam programistów, którzy z odwagą i wiarą w swój system porzucili niepotrzebną pracę i koszty i kompletnie pominęli logowanie błędów w systemie. Jest to odważne podejście acz wydaje się nieco ryzykowne.
Na szczęście obecnie jest coraz mniej programistów lubiących życie na krawędzi i większość aplikacji podsiada moduł logowanie błędów a także standardy zastosowania tegoż. Przez ostatnie lata bardzo podniosła się świadomość potrzeby obsługi błędów a odpowiednie moduły wyrastają w aplikacjach jak grzyby po deszczu. Moduły te są odpowiednio wkomponowane w architekturę systemu, logowanie odbywa się za pomocą wystawionych przez moduł API. Korzystamy z możliwości Oracle używając PRAGMA AUTONOMOUS czy DBMS_UTILITY.FORMAT_ERROR_BACKTRACE
Także na pierwszy rzut oka wszystko ładnie pięknie.
Nie ma się do czego przyczepić. Prawda?
Przynajmniej do czasu, aż nie pojawi się problem. Zaczynamy przeszukiwać logi próbując wyłuskać problem, przeanalizować go, znaleźć przyczynę niepoprawnego działania aplikacji. Wtedy okazuje się, że wprawdzie mamy logi, tylko nie jesteśmy w stanie z nich sprawnie skorzystać. Wyszukanie danych w logach trwa wieczność. A do tego w zasadzie niby logi są, ale czy to są logi powiązane z naszym błędem? Czasem ciężko to stwierdzić.
Czy tak musi być czy może jednak gdzieś robimy błąd?
Czy możemy uczynić analizę błędów szybką, łatwą i przyjemną?
By poprawić nasz moduł logowania błędów musimy się najpierw przyjrzeć najczęstszym problemom, jakie napotykamy podczas przeszukiwania logów.
1. **Długi czas przeszukiwania logów.**
Próbujesz wyszukać błędy z danego dnia czy dla konkretnego obiektu i czekasz godzinę lub dłużej? Czy żeby przeszukać tabelę błędów musisz w pierwszym kroku zrobić
SELECT MAX(ID) FROM LOG
by następnie móc po identyfikatorze ograniczyć wyszukiwanie tabeli
SELECT * from LOG WHERE ID > max_id - 1000?
Wygląda znajomo?
2. **Krótki czas przechowania logów.**
Niekiedy jest to tylko tydzień lub dwa! W sytuacji, kiedy błąd zdarzył się wcześniej niż sięgają nasze logi mamy kłopot. Owszem, być może można logi odtworzyć z backupu. Ale jest z tym tyle kłopotu że rzadko kiedy faktycznie sięgamy po archiwa.
3. **Brak unikalności błędu**
Nie wiadomo jaki moduł czy procedura zalogowała błąd ani dla jakich danych wejściowych. Log takie jest kompletnie bezużyteczny.
4. **Zbyt ogólne błędy**
np. tylko when others a błąd w 2000 linii. Ciężko stwierdzić, który fragment wywołał błąd.
5. **Brak informacji o danych**
dla jakich wystąpił błąd – np. rachune bankowyk, numer telefonu, numer umowy, numer polisy, numer klienta itp.
6. **Brak kluczowych informacji**
Brak możliwości wyszukania błędów dla kluczowych w aplikacji obiektów np. dla danego rachunku, dla danego procesu, dla danej daty itp.
7. **Zbyt dużo ilość rekordów w logu**
Zbyt duża ilość danych w logach skutkuje długim czasem wyszukiwanie i/lub krótkim czasem przechowywania logów (miejsce!!). Logowanie informacji, że proces zakończył się sukcesem jest zdecydowanie nadmiarowe. Informacje o starcie czy zakończeniu procesu można logować do innej tabeli, która by przechowywała informacje o uruchomieniu poszczególnych procesów.
Problemów jest jak widać sporo. A pewnie każdy do powyższej listy jest w stanie dodać na bazie własnego doświadczenia jeszcze kilka.
Czy możemy coś zrobić, by w prosty sposób pozbyć się powyższych niedogodności?
Jak przyjrzymy się jeszcze raz powyższym problemom możemy zauważyć, że można je podzielić na dwie kategorie - jedna kategoria dotyczy dużej ilości danych a co za tym idzie wydajności przeszukiwania logów. Drugi typ problemów to brak czy niewystarczające informacje w logach.
Zacznijmy może od tego, jakich informacji nam brakuje.
**Jakie informację powinniśmy logować?**
- miejsce wystąpienia błędu, pakiet, procedura, linia.
- jaki błąd wystąpił - pamiętajmy, by kod błędu/typ czy cokolwiek co identyfikuje nam błąd był unikalny w kodzie aplikacji, tak by móc bez wątpliwości wskazać miejsce wystąpienia błędu
- opis błędu - tutaj nie zawsze kod oraclowy błędu jest wystarczający. Często warto zalogować również biznesowy opis błędu np. nie tylko no_data_found ale np. brak otwartego rachunku dla klienta.
- dane, dla których wystąpił błąd - ta informacja jest bardzo często pomijana a jest bardzo istotna. Bez informacji, dla jakich danych wystąpił błąd, nie będziemy w stanie zanalizować przyczyny wysępienia zalogowanego błędu czy zreplikować danego błędu. Jeśli wystąpił błąd no_data_found powinniśmy zalogować wszystkie zmienne, dla których wykonywaliśmy wyszukiwanie. Bardzo przydatne byłoby również zalogowanie parametrów wejściowych procedury, dla których została wywołana, by móc w ramach analizy uruchomić tę procedurę z dokładnie takimi samymi ustawieniami.
- DATY - data wystąpienia błędu sysdate ale również data aplikacji!
- KLUCZOWE DANE APLIKACJI - takie jak numer karty czy rachunku dla systemów bankowych, numer telefonu, klienta czy umowy dla systemów telekomunikacji, numer polisy czy ubezpieczonego dla systemów ubezpieczeniowych.
Często będziemy chcieli przeszukiwać logi po tych danych. Będziemy chcieli sprawdzić, czy dla danego klienta wystąpił błąd czy nie. Bez zalogowania tych informacji nie będziemy w stanie! Przeglądanie oczami logów by sprawdzić, czy gdzieś może jest zalogowany błąd na nasz ID klienta to koszmar. I farsa.
Trudność jednak tutaj jest taka, że nie do wszystkich procedur/funkcji przekazujemy w parametrach te dane, po prostu ich nie potrzebujemy. Żeby wyliczyć datę początku najbliższego kwartału nie potrzebujemy Id klienta przecież!
Rozwiązań jest kilka:
- możemy przyjąć zasadę żeby zawsze przekazywać kluczowe dla aplikacji dane do wszystkich procedur nawet do procedur liści
- możemy trzymać w zmiennych globalnych kluczowe informacji i z nich korzystać przy logowaniu błędów
- możemy też przekazywać z niższych procedur wyjątki wyżej i logować błędy w głównych/sterujących procedurach, gdzie mamy dostępne wszystkie istotne i kluczowe informacje.
Który sposób wybierzemy nie ma w sumie większego znaczenia. Ważne jest, by przy każdym zalogowanym błędzie były pełne informacje na temat kluczowych dla naszej aplikacji danych (klient, umowa, polisa, rachunek, nr telefonu itp), datę wystąpienia błędy - tak sysdate jak i datę aplikacji, wszystkie parametry, przy których wystąpił błąd oraz miejsce w kodzie, który spowodował błąd.
Jak poprawić wydajność przeszukiwania logów?
Jak już mamy pologowane wszystkie potrzebne informacje możemy wrócić do kwestii wydajnościowej.
Problemy wydajnościowe przy przeszukiwaniu tabeli logów wynikają głównie z tego, że nawet jak logujemy właściwe/pełne informacje, to trzymamy je zwykle w jednej kolumnie typu varchar. Tam trzymamy komunikaty błędu, kluczowe dane, dla których wystąpił błąd, jeśli je logujemy itp. Problemem po prostu jest to, że na takiej kolumnie nie jesteśmy w stanie założyć skutecznego indeksu!
Ale skoro podjęliśmy już wyżej prawidłowe decyzje, że będziemy logować daty wystąpienia błędu oraz kluczowe dla aplikacji dane - co szkodzie te dane zapisywać w osobnych kolumnach tabeli?
Przecież dobrze wiemy, jakie dane w naszej aplikacji są kluczowe! Dodajmy do tabeli logów kolumny z datami, kolumny z id klienta, numerem telefonu, polisy czy karty. I załóżmy na tych kolumnach indeksy!
Dzięki temu wyszukiwanie stanie się łatwe i szybkie. Będziemy mieć prosty dostęp do błędów oraz kluczowych informacji na temat danego błędu. Będziemy mogli wyszukać wszystkie błędy, które wystąpiły przy przetwarzaniu danych konkretnego klienta, czy w konkretnej procedurze. Wszystkie informacje prosto podane!
No i skoro wyszukiwanie logów będzie szybkie - nie będzie potrzeby czyszczenia tabeli logów tak często!
Tak, kilka dodatkowych kolumn, parę indeksów a nasz moduł logowania błędów zmieni oblicze na całkiem całkiem przyjazne a analiza błędów przestanie być koszmarem :)
Przykład "starej" tabelki:
| ID | 123 |
| ERRCODE | ERR1 |
| MESSAGE | Klient:123, produkt: SILVER, procedura:calc_balance, |
| ORAMESSAGE | no_data_found |
Nowa tabelka:
| ID | 123 |
| PROCES | BALANCE |
| PROCEDURE | calc_balance |
| DATE_IN | 16-03-2019 16:03 |
| DATE_APP | 15-03-2019 |
| CLIENT_ID | 123 |
| PRODUCT_ID | SILVER |
| MESSAGE | PARAMS: par1: A, par2:444, |
| ORAMESSAGE | no_data_found |
| BACKTRACE | procedura calc_balance, line 445 |
Na nowych polach: DATE_IN, DATE_APP, CLIENT_ID możemy założyć indexy, dzięki czemu wyszukanie odpowiednich danych z logów błędów będzie bardzo łatwe i szybkie.
A podczas analizy błędów będziemy mogli się skupić na rozwiązaniu problemu zamiast frustrować się nieskończonym kłopotami z wyszukaniem odpowiednich logów.
Komentarze
Prześlij komentarz