Jakie są wzorce i anty-wzorce rejestrowania aplikacji? [Zamknięte]

66

Niedawno musiałem zbadać problem dotyczący naszej aplikacji dla dużych przedsiębiorstw. Byłem przerażony dziennikami, które musiałem przeczesać, próbując znaleźć problem, a na koniec dzienniki wcale nie pomogły w identyfikacji / izolacji błędu.

Uwaga: Rozumiem, że nie wszystkie błędy można wykryć za pomocą dzienników. Nie zmienia to faktu, że kłody są okropne.

Istnieją pewne oczywiste problemy z logowaniem, które możemy już spróbować naprawić. Nie chcę ich tutaj wymieniać i nie mogę po prostu pokazać wam naszych plików dziennika, abyście mogli udzielić porady, co robić.

Zamiast tego, aby ocenić, jak źle sobie radzimy przy logowaniu, chciałbym wiedzieć:

  1. Jakie są ewentualne wytyczne dotyczące rejestrowania aplikacji, zwłaszcza dużych aplikacji.
  2. Czy są jakieś wzorce, których powinniśmy przestrzegać, lub anty-wzorce, o których powinniśmy wiedzieć?
  3. Czy jest to ważna rzecz do naprawienia, czy może to nawet zostać naprawione, czy wszystkie pliki dziennika są po prostu ogromne i potrzebujesz dodatkowych skryptów do ich analizy?

Uwaga dodatkowa: używamy log4j.

c_maker
źródło

Odpowiedzi:

55

Kilka punktów, które moja praktyka okazała się przydatna:

  • Zachowaj cały kod logowania w kodzie produkcyjnym. Masz możliwość włączania mniej / bardziej szczegółowego logowania w produkcji, najlepiej dla podsystemu i bez restartowania programu.

  • Spraw, by dzienniki były łatwe do parsowania grepokiem i okiem. Trzymaj się kilku wspólnych pól na początku każdej linii. Zidentyfikuj czas, ważność i podsystem w każdej linii. Wyraźnie sformułuj wiadomość. Spraw, aby każdy komunikat dziennika był łatwy do mapowania do linii kodu źródłowego.

  • Jeśli wystąpi błąd, spróbuj zebrać i zapisać jak najwięcej informacji. Może to potrwać długo, ale jest OK, ponieważ normalne przetwarzanie i tak zakończyło się niepowodzeniem. Nie trzeba czekać, gdy ten sam warunek wydarzy się w produkcji z dołączonym debuggerem, jest bezcenny.

Dzienniki są głównie potrzebne do monitorowania i rozwiązywania problemów. Postaw się w sytuacji narzędzia do rozwiązywania problemów i zastanów się, jakie dzienniki chcesz mieć, gdy dzieje się coś złego lub wydarzy się w środku nocy.

9000
źródło
10
Podoba mi się ta odpowiedź, ale dodam, że ważne jest, aby rejestrować, jaki wybór został dokonany w punktach decyzyjnych. Widziałem wiele systemów, w których zarejestrowano wiele śmieci, ale kluczowe decyzje nie były rejestrowane. Więc 95% rejestrowania jest w zasadzie bezużyteczne. Również w przypadku systemów typu żądanie / odpowiedź ważniejsze jest, aby móc logować się na żądanie niż według podsystemu.
Kevin
4
+1. Podoba mi się twoja uwaga na temat postawienia się w sytuacji narzędzia do rozwiązywania problemów. Wygląda na to, że wyciągi z dziennika powinny zawierać dużo więcej wysokiej jakości komunikatów niż to, co robiliśmy ...
c_maker
1
Należy pamiętać, że rejestrowanie błędów należy rejestrować w odpowiednim dzienniku zdarzeń, a także w dziennikach aplikacji.
Steven Evers,
2
@SnOrfus: Istnieje wiele sposobów przechowywania dzienników, ale istotą jest to, że wiadomości dziennika muszą być dostępne do ostatniej sekundy awarii systemu - jak czarna skrzynia samolotu. Jeśli korzystasz z dowolnego buforowania, podaj opcję ominięcia go / opróżnienia każdej wiadomości.
rwong
1
@Rig: z drugiej strony wiele domowych programów rejestrujących nie wdrożyło żadnego buforowania (i obowiązkowo opróżnia każdą wiadomość), co prowadzi do bardzo niskiej wydajności. Dlatego musi być opcjonalny.
rwong
28

Pracuję z krytycznymi dla bezpieczeństwa systemami czasu rzeczywistego, a logowanie jest często jedynym sposobem na złapanie rzadkich błędów, które pojawiają się raz niebieski księżyc w każdy 53 wtorek, gdy jest pełnia, jeśli złapiesz mój dryf. Ten rodzaj powoduje, że masz obsesję na punkcie tego tematu, więc przepraszam teraz, jeśli zacznę pienić się w usta. Poniższe napisano dla dzienników debugowania kodu natywnego, ale większość z nich dotyczy również zarządzanego świata ...

Użyj plików dziennika tekstowego. Wydaje się to oczywiste, ale niektórzy próbują generować binarne pliki dziennika: to po prostu głupie, ponieważ nie muszę szukać narzędzia czytającego, gdy jestem w terenie. Plus, jeśli jest to tekst, a debugowanie jest pełne, istnieje duża szansa, że ​​inżynier terenowy może odczytać plik i zdiagnozować problem, nie wracając do mnie. Wszyscy wygrywają.

Projektuję systemy, które są w stanie zarejestrować prawie wszystko, ale domyślnie nie włączam wszystkiego. Informacje debugowania są wysyłane do ukrytego okna dialogowego debugowania, które sygnalizuje je znacznikiem czasowym i wysyła do pola listy (ograniczone do około 500 linii przed usunięciem), a okno dialogowe pozwala mi je zatrzymać, automatycznie zapisać w pliku dziennika lub przekierować do dołączony debugger. To przekierowanie pozwala mi zobaczyć, jak dane wyjściowe debugowania z wielu aplikacji są porządnie zserializowane, co może czasem uratować życie. I wykorzystywane do korzystania numerycznych poziomów rejestrowania (wyższa ustawić poziom, tym więcej można uchwycić):

off
errors only
basic
detailed
everything

ale jest to zbyt mało elastyczne - gdy zmierzasz w stronę błędu, bardziej efektywne jest skupienie się na logowaniu dokładnie na tym, czego potrzebujesz, bez konieczności przechodzenia przez mnóstwo detrytusu, i może to być jeden szczególny rodzaj transakcji lub operacji to powoduje błąd. Jeśli wymaga to włączenia wszystkiego, po prostu utrudniasz sobie pracę. Potrzebujesz czegoś drobniejszego.

Teraz przechodzę do logowania w oparciu o system flag. Wszystko, co jest rejestrowane, ma flagę opisującą rodzaj operacji, a zestaw pól wyboru pozwala mi zdefiniować, co zostanie zarejestrowane. Zazwyczaj ta lista wygląda następująco:

#define DEBUG_ERROR          1
#define DEBUG_BASIC          2
#define DEBUG_DETAIL         4
#define DEBUG_MSG_BASIC      8
#define DEBUG_MSG_POLL       16
#define DEBUG_MSG_STATUS     32
#define DEBUG_METRICS        64
#define DEBUG_EXCEPTION      128
#define DEBUG_STATE_CHANGE   256
#define DEBUG_DB_READ        512
#define DEBUG_DB_WRITE       1024
#define DEBUG_SQL_TEXT       2048
#define DEBUG_MSG_CONTENTS   4096

Ten system rejestrowania jest dostarczany z wersją kompilacji wersji , domyślnie włączoną i zapisującą do pliku. Jest za późno, aby dowiedzieć się, że powinieneś się logować PO wystąpieniu błędu, jeśli błąd występuje tylko raz na sześć miesięcy i nie możesz go odtworzyć. Rejestrowanie, które działa tylko z kompilacjami debugowania, jest po prostu. Równina. głupi.

Oprogramowanie zazwyczaj jest dostarczane z włączonymi BŁĘDAMI, PODSTAWOWYMI, STANEM_ZMIANY i WYJĄTKIEM, ale można to zmienić w terenie za pomocą okna dialogowego debugowania (lub ustawienia rejestru / ini / cfg, w którym te rzeczy są zapisywane).

No i jedno - mój system debugowania generuje jeden plik dziennie. Twoje wymagania mogą być inne. Ale upewnij się, że kod debugowania rozpoczyna każdy plik od daty, wersji uruchomionego kodu i, jeśli to możliwe, jakiegoś znacznika identyfikatora klienta, lokalizacji systemu lub cokolwiek innego. Możesz dostać miszmasz plików dziennika przychodzących z pola i potrzebujesz trochę informacji o tym, skąd pochodzą i jaka wersja systemu, na którym działali, która jest w samych danych, i nie możesz ufać klientowi / inżynier terenowy, który powie ci, którą wersję ma - może po prostu powiedzieć, którą wersję MYŚLĄ, którą mają. Co gorsza, mogą zgłaszać wersję exe, która znajduje się na dysku, ale stara wersja nadal działa, ponieważ zapomniały zrestartować się po wymianie. Niech Twój kod powie ci sam.

Wreszcie, nie chcesz, aby Twój kod generował własne problemy, więc włącz funkcję timera, aby wyczyścić pliki dziennika po tylu dniach lub tygodniach (po prostu sprawdź różnicę między czasem teraz a czasem utworzenia pliku). Jest to OK w przypadku aplikacji serwerowej, która działa cały czas, w aplikacji po stronie klienta możesz uzyskać usunięcie starych danych podczas uruchamiania. Zwykle oczyszczamy się po około 30 dniach, w systemie bez częstych wizyt inżyniera możesz chcieć zostawić go na dłużej. Oczywiście zależy to również od rozmiaru plików dziennika.

Bob Moore
źródło
1
+1 Ogólnie doskonała odpowiedź, ale zwłaszcza w celu umieszczenia identyfikatora aplikacji i informacji o wersji w pliku dziennika, niestety jest to bardzo często pomijane.
Binary Worrier,
27

Moim ulubionym zasobem publicznym dotyczącym wskazówek dotyczących rejestrowania są Apache JCL Best Practices .

Najlepsze praktyki dla JCL są przedstawione w dwóch kategoriach: Ogólne i Enterprise. Ogólne zasady są dość jasne. Praktyki korporacyjne są nieco bardziej zaangażowane i nie zawsze jest jasne, dlaczego są ważne.

Zasady najlepszych praktyk stosowanych w przedsiębiorstwie dotyczą komponentów oprogramowania pośredniego i narzędzi, które powinny zostać uruchomione w środowisku „Enterprise”. Problemy te dotyczą rejestrowania jako internacjonalizacji i wykrywania błędów. Przedsiębiorstwo wymaga większego wysiłku i planowania, ale zdecydowanie zachęca się (jeśli nie jest to wymagane) w systemach na poziomie produkcji. Różne korporacje / środowiska mają różne wymagania, więc elastyczność zawsze pomaga ...

Pomimo celowania w JCL, wydają się one na tyle ogólne, że można je ogólnie przyjąć do logowania.

  • Moje osobiste „wytyczne” dotyczące rejestrowania są takie, że na poziomie debugowania staram się, aby moje dzienniki były czytane jak historia - z logiką zrozumiałą i wystarczającymi (ale nie przeciążonymi) szczegółami.

Najsłynniejszym anty-wzorem jest prawdopodobnie „połykanie wyjątków” - wystarczy wyszukać go w Internecie.

Jeśli chodzi o ogromne pliki logowania, w mojej praktyce był to w większości normalny przypadek. I tak, dodatkowe skrypty, jak je nazywasz i / lub narzędzia takie jak Piła łańcuchowa również dla mnie wyglądają normalnie.

  • Powyższe nie oznacza jednak, że zawsze musisz ślepo umieścić wszystkie dzienniki w jednym wielkim pliku. Czasami przydatne może być zapisywanie / kopiowanie niektórych dzienników do oddzielnych plików. Np. W moim ostatnim projekcie pracownicy QA poprosili o dedykowane pliki danych i danych dotyczących pomiaru czasu oraz o krótkie raporty z operacji systemu. Powiedzieli, że skorzystają na tym i programista to zrobił (korzyść z pliku krótkich raportów okazała się naprawdę znacząca).

PS. Jeśli chodzi o anty-wzory, inne, które przychodzą na myśl, to „powódź” i bezsensowne wiadomości.

  • Nazywam to zalewaniem, gdy widzę wiele podobnych wiadomości pochodzących z pętli z wieloma iteracjami. Dla mnie powódź jest na tyle denerwująca, że ​​próbuję się jej pozbyć po wykryciu w kodzie źródłowym. Zwykle ulepszanie go wymaga trochę sztuki - ponieważ cóż, rzeczy, które dzieją się w pętli, mogą być interesujące. Kiedy nie mam czasu na głębszą poprawę, staram się przynajmniej zmienić poziom rejestrowania takich wiadomości na najniższy, aby ułatwić odfiltrowanie.

  • Wiadomości bezsensowne wydają się być dość popularnym śmieciem. Wyglądają one nieszkodliwie, gdy wczytywane są w kodzie źródłowym - chyba trzeba przejść przez proces analizowania wyników debugowania wyglądających jak ...

    step #1
    step #2
    step #3
    

    ... aby głęboko docenić ich nieodłączną brzydotę. Moją ulubioną heurystyką do wykrywania tego rodzaju problemów na poziomie kodu źródłowego (zaproponowaną przez współpracownika w jednym z moich wcześniejszych projektów) jest obliczenie liczby wystąpień symboli spacji w literałach łańcuchowych używanych podczas logowania. Z mojego doświadczenia wynika, że ​​zero spacji zasadniczo gwarantuje, że instrukcja rejestrowania jest bezsensowna, jedna spacja jest również dobrym wskaźnikiem potencjalnego problemu.

komar
źródło
4
Aby uniknąć powodzi, zwykle zbieram heurystykę pętli i wyprowadzam ją po pętli. Oznacza to, że wszystko, co dzieje się w pętli, powinno być przechowywane w zmiennej (jak somethingSpecialHappenedCount), a następnie przesyłane do rejestratora.
Spoike
@Spoike good point! przechowywanie w zmiennej jest rzeczywiście jedną z moich ulubionych ulubionych sztuczek w walce z powodzią
komara
1
Wyprowadzam wszystkie różne liczniki do rejestratora jako tabelę ASCII w dzienniku po zakończeniu pętli, aby można je było łatwo porównać. Pomysł na tabelę został zainspirowany tym, który generuje Spring's StopWatch.prettyPrint () . Poza tym sprawienie, by tekst dziennika był czytelny i odpowiedni, jest nadal „sztuką”, jak wspomniano wcześniej w odpowiedzi.
Spoike
@Spoike: (i @gnat) To interesujące. Więc w zasadzie dodajesz rzeczywisty kod do logiki biznesowej tylko w celu logowania? Nigdy o tym nie słyszałem ani nie robiłem tego i nie jestem pewien, jak uzasadnię to moim współpracownikom. Obawiam się, że jeśli zaczniemy to robić, niektórzy z naszych programistów zaśmiecą kod źródłowy w takim stopniu, że logika biznesowa stanie się skomplikowana i trudna do odczytania. Już samo zalogowanie instrukcji powoduje, że źródło wygląda brzydiej.
c_maker
2
@c_maker Twój punkt widzenia na temat łączenia rejestrowania z logiką biznesową jest wart dedykowanego pytania. Osobiście nie mam jeszcze silnej opinii na te tematy. Teoretycznie można sobie wyobrazić pewne ulepszenia separacji za pomocą AOP i iirc, istnieją nawet praktyczne zastosowania tego podejścia. W praktyce jednak trzymam się podejścia „mieszanego” i jak dotąd nie miałem z nim większych problemów. Zaśmiecanie kodu źródłowego jest prawdziwym niebezpieczeństwem, ale jak do tej pory udało mi się sprawić, że współistnieje z kodem logowania całkiem „pokojowo”. To oczywiście wymaga pewnego wysiłku.
komara
11

Zaloguj wyjątek tylko raz!

Jednym z typowych problemów, które zauważyłem, jest rejestrowanie i ponowne zgłaszanie wyjątku. W rezultacie pliki dziennika zawierają kilka razy te same wyjątki na kilku poziomach stosu.

Nayaki
źródło
5

Oto anty-wzorzec: Utworzenie dwóch tuzinów „zmiennych ogólnych” w tabeli bazy danych w celu śledzenia wszystkiego, co możliwe, a następnie posiadanie 88 (i zliczanie) różnych wartości wyliczeniowych dla różnych typów dzienników.

Wayne Molina
źródło
+1 - widziałem to. „Tabele błędów”, które mają kolumny takie jak string1, string2, string3, string4, string5, przy czym konkatacja wszystkich kolumn spowoduje kod błędu, do którego nie odwołuje się żadna dokumentacja. W rezultacie rejestrowanie jest mylące i bezużyteczne; znany również jako „aplikacja-zewnętrzna-korporacyjna-z-niestandardowym-programowaniem-debugowaniem-piekło”.
Morgan Herlocker,
W moim przypadku jest to „system rejestrowania ręcznie walcowane bez żadnego pomysłu na to, co rzeczywiście wymaga logowania”
Wayne Molina
4

Moje doświadczenie z logami jest tym większe, im lepsze, ale na tyle spójne, aby można je było filtrować według komputera i móc skonfigurować poziom ważności dla każdego komponentu aplikacji osobno.

Ponadto bardzo trudno jest przewidzieć, jakie logowanie będzie potrzebne do znalezienia przyszłego błędu. Większość oczywistych miejsc do rejestrowania błędów została naprawiona, zanim produkt wyjdzie za drzwi. Często zdarza się, że wynik zgłoszenia błędu polega na dodaniu rejestrowania w celu zdiagnozowania go, jeśli to się powtórzy.

Karl Bielefeldt
źródło
2

Kilka notatek ze strony operacyjnej domu tutaj:

1) Upewnij się, że dzienniki są konfigurowalne lokalnie, najlepiej za pomocą narzędzia nie cięższego niż edytor tekstu. Przez większość czasu nie chcemy otrzymywać rejestrowania na poziomie TRACE, ale uwielbiamy móc go włączać.

2) Jeśli to możliwe, upewnij się, że dzienniki można odczytać za pomocą narzędzia nie cięższego niż edytor tekstu. Nie ma nic gorszego niż konieczność polowania na narzędzia w dziwnej godzinie, gdy system produkcyjny zawodzi.

Wyatt Barnett
źródło
1

Z własnego doświadczenia w pracy z aplikacjami internetowymi:

(i biorąc pod uwagę, że przechowywanie jest obecnie bardzo tanie)

  • Zaloguj jak najwięcej dostępnych (w tym momencie) informacji, jak możesz.
  • Zawsze włączam DateTime.Now w moich ciągach dziennika.
  • Zawsze (jeśli to możliwe) rejestruję czas trwania określonej akcji.
  • Zachowaj spójność ze swoimi logami. Od zawsze używam tego rodzaju wzorca:

    • „[Info X] [Info Y] [Info Z] [itd.]”
sabiland
źródło
1

Oprócz stacktrace zaloguj bieżący stan aplikacji i dane wejściowe.

Oprogramowanie jest deterministyczne, te dwa są zwykle jedyną rzeczą, której potrzebujesz, aby odtworzyć błąd. Przechowywanie pełnego stanu może w niektórych przypadkach być kłopotliwe, więc sposoby na odtworzenie bieżącego stanu, na przykład przez poprzednie dane wejściowe, są również dobre.

Oczywiście więcej danych jest zawsze lepsze, ale przynajmniej te dwa są dobrym początkiem dla najłatwiejszych awarii.

ladida
źródło
3
„Oprogramowanie jest deterministyczne” => nie zawsze niestety. Pomyśl na przykład o błędach współbieżności.
assylias