Logi dla dewelopera są źródłem informacji o tym co dzieje się w systemie podczas jego działania. Nieodpowiednie ich ustawienie może powodować w najlepszym przypadku lekką nieczytelność, w najgorszym natomiast – ukryte błędy które wychodzą dopiero na produkcji.
Cześć! 🙂
W dzisiejszym artykule:
- Opowiem Ci historię o tym jak brak osoby odpowiedzialnej zabija odpowiedzialność zespołu
- Konfiguracja logback’a w spring boocie – na co zwrócić uwagę
- Kilka tipów odnośnie logów
Historia z projektu…
Ruszył mnie mail od przełożonego, który poprosił o wysłanie konfiguracji logbacka jaka miała być używany na produkcji. Mail był wysłany pod alias całego zespołu. Ja na projekcie jestem najkrócej więc uznałem, że nie będę dobrą osobą żeby na niego odpowiadać – błąd. Zachowałem go sobie i po kilku dniach do niego wróciłem.
Nigdy nie konfigurowałem logów na – nazwijmy to – większą skale i nie miałem w tym żadnego doświadczenia. Odpaliłem plik konfiguracyjny logback.xml i czytam. Czytam ustawienia (nie było ich dużo), czytam dokumentację logbacka + jakiś szybki tutorial o ustawieniach spring boot’a + logbacka.
Po zgłębieniu wiedzy teoretycznej (na ten moment wiedziałem czego powinienem się spodziewać po logach), zajrzałem do logów serwera. Logi na które patrzyłem nie raz (przecież na co dzień pracuję z tym systemem). Wywołuję akcję, która uruchamia jakiś log i widzę zduplikowany log. Niby jeden do drugiego podobny – wiadomość ta sama, stacktrace się zgadza. W jednym składnia jest kolorowana, wygląda to schludnie. W drugim natomiast odwołanie do konkretnej klasy i metody gdzie wywołany jest log, brak kolorowanej składni (nie jestem jakimś fanem tego żeby wszystko się świeciło, ale w ten sposób o wiele przyjemniej czyta się logi) + kilka innych drobnych różnic.
I może nie robiłbym z tego żadnego dramatu i nie pisał o tym na blogu. Ale taka konfiguracja utrzymywała się przez około półtorej roku!! Żeby nie było, konfiguracja nie dotyczyła środowiska produkcyjnego, ale wszystkich innych środowisk z których na co dzień korzystamy (+ nasze lokalne).
Nachodzi mnie pytanie – dlaczego tak się stało? I znajduję dwie odpowiedzi:
- Brak osoby odpowiedzialnej za logi w aplikacji
- Brak kompetencji w zespole
Numer 1. Skoro nikt nie jest odpowiedzialny to dlaczego ja mam być? Po co mam poprawiać coś co jako tako działa? Takie podejście nie jest dobre! Jeżeli widzimy (a chyba przez ten cały czas ktoś musiał to zauważyć) to dlaczego nie chcemy wziąć za to odpowiedzialności? Kieruje nami strach (że nie umiemy) czy lenistwo?
Numer 2. Tutaj mój wniosek postawiłem na zasadzie – gdyby ktoś miał kompetencje i znał temat, to by to naprawił. I też nie chcę nikogo winić, że tego nie zrobił – nie umieć, rzecz ludzka. Natomiast jeżeli chcemy aby projekt(y) nad którymi pracujemy nie zmieniały się w słynne projekty legacy, to o nie dbajmy! Użyję nawet takiego ogrodowego slangu, pielęgnujmy je.
W moim przypadku są to tylko jakieś głupie logi, ale od tego się zaczyna. Dziś logi, jutro testy, które ktoś gwarantuje, że dopisze później, a za rok szukamy nowego miejsca pracy bo projekt w jakim pracujemy to bajzel! Spuentuje to tak: jak sobie pościelisz tak się wyśpisz 🙂
Ps. jeżeli czyta to ktoś z mojego projektu, to nie bierzcie tego interpersonalnie. Chciałem podkreślić, że we wszystkim co robimy – starajmy się być solidni i dbajmy o to co rozwijamy.
Konfiguracja logback’a w spring boocie
Uff…. rozpisałem się w tej pierwszej myśli. Ten i pozostały akapit będą już sekcjami technicznymi. Ale nie napiszę Ci tutaj jak od 0 postawić projekt który będzie wyświetlał logi. Chcę tylko zwrócić uwagę na pewne rzeczy, które programiści robią często przez copy-paste, de’facto nie wiedząc co robią (w efekcie czego działa to jako tako).
W kilku projektach spotkałem się z taką implementacją logback-spring.xml – umiesz powiedzieć co jest nie tak?
1 2 3 4 5 6 7 8 9 10 11 12 13 | <?xml version="1.0" encoding="UTF-8"?> <configuration> <include resource="org/springframework/boot/logging/logback/base.xml"/> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}:${HOSTNAME} %highlight(%-5level) %thread --- %logger{36} : %msg%n </pattern> </encoder> </appender> <root level="INFO"> <appender-ref ref="STDOUT"/> </root> </configuration> |
Wiem, że to mała rzecz… ale zwróć uwagę na include. Jeżeli zajrzymy do środka to zauważymy, że dzięki jednemu include’owi dostajemy w gratisie 2 appendery. Console i file output – co prawda, ten drugi nie zadziała dopóki nie zdefiniujemy w application.properties logging.path. Btw. tutaj znajdziesz wszystko co powinieneś wiedzieć o ustawieniach logów w spring boocie.
Wracając do ustawień logów wyżej. Przy aktualnym ustawieniu nasz output będzie zduplikowany! Taki właśnie problem mieliśmy u siebie na projekcie. Nikt nie pomyślał o tym, żeby sprawdzić co dostajemy zaciągając ustawienia z base.xml. A tam właśnie dostajemy już fajnie przygotowany console appender. Warto też dodać, że używając startera spring boota (a jak używamy spring boota, to startera pewnie też), jeżeli nie będziemy majsterkować niczego przy logach to z automatu dostajemy domyślnego logback’a z konfiguracją z base.xml.
By default, if you use the “Starters”, Logback is used for logging.
Warto też dodać, że jeżeli używamy logbacka to odpowiednio nazwijmy nasz plik konfiguracyjny. Do wyboru mamy 4 opcje: logback-spring.xml
, logback-spring.groovy
, logback.xml
, lublogback.groovy
. Jednak tutaj, znów z pomocą przychodzi nam dokumentacja:
When possible, we recommend that you use the -spring variants for your logging configuration (for example, logback-spring.xml rather than logback.xml ). If you use standard configuration locations, Spring cannot completely control log initialization. |
Kilka tipów odnośnie logów
Na koniec chcę każdemu devowi chcę podrzucić kilka porad, na co zwracać uwagę przy ustawieniach logback’a.
- Na środowiskach nieprodukcyjnych ’rozluźnij’ logowanie – co mam na myśli? Większość z nas używa jakiegoś framework’a który będzie generował zapytania do bazy. Może się zdarzyć tak, że zamiast wykonać jedno zapytanie, wykonujemy ich 50 – bo złapaliśmy się na problem N+1. Nie mając odpowiednich logów, możemy się o tym nie dowiedzieć. W najlepszym przypadku spowolnimy nieco działanie systemu, w najgorszym zabijemy go wykonując miliony niepotrzebnych zapytań.
- Jeżeli pracujesz ze spring-bootem i używasz logbacka, przygotuj profil logów dla środowiska produkcyjnego. Dzięki temu, nie będziesz zaskoczony gdy ktoś Cię o to poprosi. Pamiętaj tylko, że tutaj polityka logowania powinna być już odpowiednio zaostrzona. Do jakiego poziomu? To zależy – takiego, który nie będzie w żaden sposób inwazyjny dla aplikacji i jednocześnie będzie mógł dać Ci informację co się stało w przypadku błędów. Jeżeli podczas developmentu będziesz stosować się do punktu 1 to prawdopodobnie warn lub error dla większości środowisk będzie odpowiedni (wybadaj to wcześniej na jakimś środwisku testowym).
- Ucz innych – jeżeli masz wiedzę w tym zakresie, to edukuj swoich współpracowników i zachęcaj żeby sami potestowali różne ustawienia. Dziel się wiedzą na projektowych sharepointach czy confluencach. To sprawi, że nowe osoby, wchodzące na projekt będą miały referencję i będą znały standardy jakich używacie w projekcie. Dzięki wiedzy ogólnej, nikt nie będzie w stanie zrobić bałaganu cichaczem i czegoś pozmieniać. Świadomość zespołu zawsze wpłynie pozytywnie na projekt.
Podsumowanie
Celem tego wpisu było zasianie motywacji. Motywacji do tego żeby dbać o to co robimy. Większość z nas pracuje dla biznesów, które czerpią z tego zyski – a jeżeli biznesowi wiedzie się dobrze to i nam będzie dobrze. Po za aspektami czysto finansowymi uważam, że to, co każdy z nas wytwarza pokazuje charakter człowieka. Są ludzie, którzy zawsze będą robili wszystko na odwal, aby było – nie potępiam (taki charakter) ale też nie szanuję. Wracając do samych logów, korzystaj z gotowych rozwiązań (np. dostarczanych przez springa), korzystaj z dokumentacji i testuj. Jeżeli coś nie działa to to popraw. Weź odpowiedzialność na siebie – opłaci się.
Za Tydzień
Weźmiemy na tapetę EntityManagera. Będzie bardzo technicznie 🙂