• Krzysztof Borkowski

Fail Fast... or die! (część I)

Wyobraź sobie, że jesteś developerem bardzo dużego systemu IT. Niech to będzie system księgowy dostarczony dla bardzo dużej instytucji finansowej w Europie - nazwijmy ją ACME. Właśnie skończył się miesiąc i ACME zleciła w Twoim systemie wykonanie raportu pt. "bilans miesiąca". Okazuje się, że bilans się nie zgadza. Brakuje, ups, miliona euro. Od tej chwili sprawy toczą się jak akcja w książkach Toma Clancy'ego.


Dzień 1, godzina 08:00

ACME właśnie przekazało kierownikowi projektu w Twojej firmie, że w bilansie miesiąca brakuje miliona euro. Kierownik przyjmuje wiadomość ze spokojem - nie takie już problemy w życiu widział. Przekazuje tę wiadomość głównemu analitykowi w projekcie. Ten, po otrzymaniu informacji, robi się blady.


Dzień 1, godzin 10:00

Główny analityk już od dwóch godzin pracuje nad problemem. Przed chwilą poprosił o pomoc developera (Piotra) odpowiedzialnego za zaimplementowanie mechanizmu liczenia bilansu miesiąca. Celem jest sprawdzenie, czy błąd jest w mechanizmie liczenia bilansu, czy może bilans policzył się dobrze, ale dane na których prowadził obliczenia były uszkodzone.

Dzień 1, godzin 21:00

Główny analityk oraz Piotrek wciąż siedzą w biurze i analizują dane. Od rana nic nie jedli. Zadanie nie jest proste. W ostatnim miesiącu w bazie danych pojawiło się 30 milionów nowych rekordów. Jest więc co analizować. Mózgi im już parują.


Dzień 2, godzin 02:00

Główny analityk oraz Piotrek czują mdłości. Wciąż nie wiedzą co się dzieje. Mają dosyć. Każdy z nich zamawia Ubera i wracają do domów. Główny analityk nie może jednak zasnąć - nie przypomina sobie, kiedy po raz ostatni był pod taką presją.

Dzień 2, godzina 09:00

Główny analityk i Piotrek są już w pracy.

Dzień 2, godzina 23:40

Główny analityk i Piotrek właśnie odkryli gdzie jest problem. Algorytm tworzenia bilansu miesiąca jest prawidłowy (Piotrek odetchnął z ulgą - ktoś inny ma przerąbane). Bilans został wykonany na danych, które są uszkodzone. Takie dane pojawiają się od dwóch dni (tak więc na nieszczęście bug, utrwalił się w danych). Z jakiegoś powodu (nie wiedzą jakiego) od dwóch dni system zwraca podmiotom związanym z ACME po raz drugi pieniądze, które raz już zostały im zwrócone. Innymi słowy milion euro został niesłusznie wysłany do osób i instytucji, które nie powinny tych pieniędzy dostać (tak więc bug ma swoje skutki pozasystemowe). Takich osób i instytucji jest... cztery tysiące. Szybko liczą, że skoro problem zaczął występować dwa dni przed wykonaniem bilansu miesiąca, a oni dwaj przez dwa dni szukali źródła problemy to znaczy, że problem występuję już nie dwa, a cztery dni. Wobec tego najpewniej nie jeden lecz dwa miliony zostały niesłusznie przelane do innych osób i instytucji, których teraz będzie nie cztery, a... osiem tysięcy... obaj myślę: "o ku....". Wiedzą też, że:

  1. ACME będzie musiało uruchomić procedurę ściągania niesłusznie przelanych pieniędzy od osób i instytucji, które je dostali. Skoro jest to 8000 osób i instytucji to będzie trzeba wysłać 8000 pism wyjaśniających. Jeżeli przygotowanie takiego pisma zajmie księgowej 20 minut, to na całą akcję potrzeba 8000 * 20 = 160 000 minut, czyli 2666 godzin. W tygodniu jest 40 godzin pracy, więc żeby obsłużyć temat w tydzień potrzeba będzie na to 67 osób. Obydwu przez głowę przechodzi ta sama myśl: "ja pier....".

  2. Należy zatrzymać w systemie możliwość generowania zwrotów do czasu naniesienia poprawki, żeby nie pogarszać sytuacji.

  3. Dane trzeba poprawić. Do poprawy jest co najmniej osiem tysięcy rekordów. Główny analityk już wie, że najbliższe dwa tygodnie spędzi w biurze (znów myśli: "ja pier.....").

  4. Trzeba znaleźć błąd w kodzie i poprawić go.

Dzień 3, godzina 08:00

O tej nieludzko wczesnej porze, z pięknego snu o kitesurfingu na Kos w Grecji, zostaje wyrwany front-end developer - Paweł. Kierownik projektu mówi mu, że jego zadaniem jest jak najszybciej zablokować przyciski i inne elementy interfejsu użytkownika pozwalające na wystawianie zwrotów w systemie. Na pytanie, czy może zająć się tym po śniadaniu słyszy... "nie". Parę minut później telefon dostaje Michał - backend developer, główny programista modułu zwrotów. Właśnie, szczęśliwy, odprowadza swoją pięcioletnią córkę do przedszkola - rozmawiają o tym, jaki smak lodów jednorożce lubią najbardziej. W telefonie jednak słyszy, że ma być w biurze jak najszybciej, bo w jego module jest ultrakrytyczny bug i że za chwilę jego moduł zostanie wyłączony.


Dzień 3, godzin 09:30

Michał dociera do biura. Po drodze policzył kilka rzeczy i kiedy doszedł do ostatecznego wyniku, poczuł ścisk w żołądku jak wówczas, kiedy jego pierwsza dziewczyna (w czwartej klasie liceum) powiedziała mu, że "chyba" jest w ciąży. Oto te obliczenia. ACME wystawia średnio dziennie zwrotów za 450 milionów euro. Każdy dzień opóźnienia w realizacji tych zwrotów skutkuje koniecznością zapłaty odsetek przez ACME tym, którym kasa ta się należy. Odsetki to 8% w skali roku, czyli każdy dzień opóźnienia będzie kosztował ACME jakieś... 100 tysięcy euro (czyli.... jakieś 400 tysięcy złotych). Michał zabiera się więc ostro do pracy. Nie ma apetytu na śniadanie. Główny analityk jest przy nim. Michał przegląda kod, a główny analityk dokumentację analityczną - kto wie, może błąd jest w analizie?


dzień 3, godzina 23:00

Michał wciąż nie wie, gdzie jest błąd. Kodu do przeanalizowania było 15 tysięcy linii. Przejrzał wszystko dwa razy. Większa jego część była pokryta testami. Razem z nim jest testerka - Iwona. Próbuje na środowiskach testowych odtworzyć błąd, ale bez powodzenia. Główny analityk również jest z nimi. Oczy ma podkrążone - to jego 3 dzień w biurze. Wszyscy troje dochodzą do wniosku, że mózgi już im się zagotowały i niczego nie wymyślą. Pora wracać do domów.


dzień 4, godzina 08:00

Cała trójka jest już w biurze. Michał twierdzi, że zasnął dopiero o 4:00 - zjada go stres. Jego moduł nawala. Z powodu wczorajszego zablokowania modułu zwrotów, ACME zapłaci 100 tysięcy euro odsetek. Na myśl o tym robi mu się niedobrze. A dzisiaj jest drugi dzień kiedy moduł ten nie będzie pracował - myśli: "kolejne 100 tysięcy euro pójdzie się je.....".


dzień 4, godzina 14:00

Cała trójka jest w biurze. Właśnie zostali zaproszeni na naradę. Biorą w niej udział: kierownik projektu, lider techniczny całego developmentu, a także Paweł (to ten co wyłączył na interfejsie możliwość wystawiania zwrotów), który do tej pory praktycznie nie był w temat zaangażowany. Na chwilę wpada też ich szef, dyrektor pionu rozwoju systemów. Chce im jakoś pomóc. Chce podnieść ich motywację. Mówi im więc, że jeżeli nie rozwiążą tego problemy do końca następnego dnia to jego kariera w tej firmie zapewne zostanie zakończona, ale niech będą pewni, że "niczym upadający rycerz, zdąży jeszcze dobyć miecza i odciąć im nogi" - potem wychodzi. Michał jakoś nie poczuł się bardziej zmotywowany (dziwne). Zaczął za to zastanawiać się, gdzie na jego prywatnym kompie znajduje się najbardziej aktualna wersja CV. Ustalony zostaje jednak następujący plan:

  1. Po pierwsze przywrócone zostanie działanie modułu zwrotów (Paweł, bardzo się na tę wiadomość ucieszył - wreszcie będzie mógł potestować komendę git revert).

  2. Michał zmienie uprawnienia do webserwisu, który jest odpowiedzialny za generowanie zwrotów. Stworzy nową specjalną rolę, która będzie miała prawo wywołać ten webserwis. Rolę tę przyzna tylko jednej osobie w całym ACME.

  3. Iwona następny dzień spędzi na pracy zdalnej z osobą z ACME mającą tę specjalną rolę i postara się odtworzyć sytuację na produkcji - nie ma innego wyjścia, w środowiskach testowych problem nie występuje.

dzień 4, godzina 20:00

Nowa wersja aplikacji została zainstalowana na środowisku produkcyjnym. W prace nad jej wydaniem zaangażowanych było 2 developerów, 2 testerów, kierownik projektu, kierownik projektu po stronie ACME, administrator środowiska - łącznie 7 osób. W sali obok widać głównego analityka, który razem z developerem baz danych zaczyna przygotowywać skrypty prostujące dane w bazie danych.


dzień 5, godzina 08:00

Wszyscy są w biurze i czekają z niecierpliwością na feedback od Iwony, która już pracuje z księgową z ACME.


dzień 5, godzina 10:15

Iwona wraz z księgową z ACME znalazły przypadek, dla którego występuje błąd. Podaje id nadpłaty, dla której możliwe jest stworzenie zwrotu, chociaż już raz nadpłata ta była pewnej osobie zwrócona. Iwona donosi, że nadpłata pojawia się na liście nadpłat do zwrotów - a nie powinna, tam powinny być wyświetlane tylko te nadpłaty, dla których nie zrealizowano zwrotów. Michał twierdzi, że to jest niemożliwe. Zapytanie zwracające nadpłaty do zwrotu wygląda bowiem tak:

from Nadplata n where n.hasZwrotBeenIssued = false

Cóż.... nie należy do najbardziej skomplikowanych.


Michał myśli więc, bardzo słusznie zresztą: "ku.... to musi działać". W akcie desperacji i niedowierzania dochodzi do wniosku, że musi dodać logi. Dodaje je w dwóch miejscach:

  1. w metodzie webserwisowej zwracającej listę nadpłat do zwrotu oraz,

  2. w metodzie webserwisowej przyjmującej id nadpłaty dla której ma zostać wystawiony zwrot.

dzień 5, godzin 12:15

Michał ma już gotową wersję do wydania na produkcję. Teraz trzeba ją jak najszybciej wydać.


dzień 5, godzina 18:00

Minęło niemal sześć godzin. Nowa wersja aplikacji jest już na produkcji. Znów, "zaledwie" 7 osób było zaangażowanych w jej wydanie. Iwona i księgowa z ACME wciąż są na stanowiskach. Iwona zauważa, że księgowa, z którą pracuje, jest jakaś "spięta" i że może mieć to związek z tym że "miała odwieźć dzieci na basen, ale jej szef powiedział, że musi zostać w robocie do skutku".


dzień 5, godzina 18:15

Iwona razem z księgową odtwarzają problem. Michał przystępuje do analizy logów. Wynika z nich jasno, że odsyła do frontu prawidłowe id-ki nadpłat (tj. takich, dla których zwroty nie zostały jeszcze wygenerowane). Z frontu jednak przychodzą id-ki nieprawidłowe. Co ciekawe nie dzieje się tak zawsze, lecz tylko dla niektórych nadpłat. W tym momencie dzieją się dwie rzeczy:

  1. Michał poczuł ulgę, jak gdyby właśnie usłyszał, że czarna plamka, którą ma na plecach, to jednak nie czerniak. Jak na prawdziwego kolegę z zespołu przystało ("kolegę" pisanego przez "ch") , pomyślał: "ufff.... na szczęście dla mnie to jednak frontendowcy coś spier.....; przez tych kretynów siedzę tutaj już trzeci dzień".

  2. Paweł zaś poczuł ucisk w żołądku. Myśli o tym, że moduł zwrotów jest wyłączony już 3 dzień z rzędu co oznacza, że ACME w tym czasie straciło z tytułu odsetek 300 tysięcy euro i że Michał bezsprzecznie udowodnił, że nie jest to wina beckendu tylko frontendu - tego frontendu, który napisał on, Paweł.

dzień 6, godzin 01:20

Paweł jest w biurze już siedemnastą godzinę... ale znalazł właśnie przyczynę problemu. Okazuje się, że id-ki obiektów "Nadpłata" są większe niż Number.MAX_SAFE_INTEGER (szczegóły znajdziesz tutaj). Problemem są więc ograniczenia JavaScriptu, który nie jest w stanie obsłużyć prawidłowo liczb większych niż Number.MAX_SAFE_INTEGER i zaczyna zapisywać w swoich zmiennych nieprawidłowe wartości.


dzień 8 godzina 08:00

Po dwóch wyczerpujących dniach pracy, wymagających zmian w kodzie front-endu i back-endu oraz solidnych testów regresji, na produkcji, wreszcie, pojawia się nowa wersja aplikacji ze skutecznym bugfixem problemu zgłoszonego 8 dni wcześniej. Moduł zwrotów znów zostaje uruchomiony. W efekcie jego wyłącznie ACME straciło na odsetkach 500 tysięcy euro (czyli jakieś.... 2 miliony złotych).


Michał jest wniebowzięty. Zeszło z niego całe ciśnienie. Ma poczucie dobrze zrobionej roboty. Poświęcił masę czasu, żeby rozwiązać ten egzotyczny problem i to on znalazł jego nietrywialne źródło. Cały dzień chodzi jakby lekko unosząc się nad ziemią, na twarzy ma wielkiego banany, do każdego zagaduje. Biedaczysko.... nie wie, że jego dni są policzone.


Jego szef nie zostanie zwolniony - jest bowiem dobrym pływakiem i bez względu na ilość i gęstość szamba zawsze będzie unosił się na jego powierzchni. Tę sztukę opanował do perfekcji. Postanowił jednak odreagować i dać przykład innym jaki jest twardy i bezwzględny - jaki jest... męski. Kompetencji mu brak, ale zaobserwował, że najbardziej zaangażowany w rozwiązanie problemu i najbardziej zestresowany był Michał w związku z czym uznał, że to on jest winien. Michał dostanie wypowiedzenie w ostatnim dniu miesiąca - to jest już pewne.


dzień 14 godzina 21:00

Po kolejnych 7 dniach główny analityk wraz z developerem baz danych poprawił w bazie dane. Zmodyfikował 8 tysięcy istniejących rekordów i dodał 16 tysięcy nowych. Ma nadzieję, że niczego nie uszkodził tymi zmianami. Wykończony wraca do domu - to były najcięższe dwa tygodnie w jego życiu.


Czy można było tego wszystkiego uniknąć?


Oczywiście, że tak! I to nie za jakąś wielką cenę, nie w jakiś wyjątkowo wyszukany i zawiły sposób. Wystarczyło dodać dwie linijki kodu, a cała ta rzeźnia w ogóle nie miałaby miejsca. O jakie dwie linijki kodu chodzi? O tym napiszę w następnej części tego tematu, dostępnej tutaj.


"One more thing..."


Ten i inne artykuły piszę po to, żeby podzielić się swoją wiedzą i doświadczeniem z innymi. Jednakże napisanie artykułu to dopiero połowa sukcesu - drugą połowę stanowi dotarcie z treścią do innych. Możesz mi bardzo pomóc w tym zadaniu - wystarczy, że klikniesz w jedną z czterech ikon poniżej i udostępnisz innym link do tego posta. Za tę pomoc będę Ci bardzo wdzięczny.