Historia pewnego błędu

W pewien poniedziałkowy poranek użytkownicy i monitoring naszego systemu zaraportowali incydent – system działał poprawnie, ale bardzo wolno.

Zabraliśmy się do roboty – jest incydent, trzeba reagować. W ruch poszły standardowe sprawdzenia: kolejki requestów na serwerach, komunikacja z innymi systemami, obciążenie maszyn, czasy odpowiedzi z bazy danych… Ale im dłużej sprawdzaliśmy, tym szerzej otwierały nam się oczy ze zdumienia. Namierzyliśmy, że coś złego dzieje się na serwerze aplikacji (middleware), który jest przeciążony – ale tutaj nasze odkrycia się skończyły. Powstawały i padały kolejne hipotezy robocze dotyczące przyczyn problemu. Serwer nie dostawał więcej requestów niż tydzień temu. Nie sprawdziła się również hipoteza, że dostaje on jakieś wyjątkowo ciężkie do przetworzenia requesty – charakterystyka ruchu była identyczna jak zwykle. Nie było opóźnień w komunikacji z innymi systemami. Ostatni release aplikacji, który mógłby być potencjalną przyczyną błędu, został wycofany i zainstalowaliśmy poprzednią wersję aplikacji. Na serwerach testowych problem nie występował. Wszystko wyglądało normalnie – oprócz tego, że serwer działał dziesięć razy wolniej niż w zeszłym tygodniu, dostawał ciężkiej zadyszki i nie radził sobie z przetwarzaniem przychodzącego ruchu.

Po południu było widać, że problem jest bardzo poważny. Działaliśmy dwutorowo: z jednej strony uruchomione zostały aktywności w celu złagodzenia skutków problemu (przeniesienie przetwarzania na mocniejszą maszynę, ograniczenie przychodzącego ruchu, poprawki i usprawnienia w konfiguracji), ale z drugiej strony wciąż staraliśmy się namierzyć rzeczywistą przyczynę błędu. A ponieważ kończyły nam się pomysły na rzeczy możliwe do sprawdzenia, zostali ściągnięci do firmy specjaliści z firm zewnętrznych.

Dopiero po 4 dniach (!) bardzo intensywnych badań, sprawdzeń, dociekań i eksperymentów odkryliśmy źródło problemu. Bezpośrednią przyczyną okazało się… dodanie kilku rekordów do tabeli parametryzacyjnej, które nastąpiło kilkanaście dni wcześniej. A clou problemu polegało na tym, że cała zawartość tej tabeli była wczytywana przez wszystkie procesy systemu do wewnętrznego bufora. Dopóki ta tabela była mała, to bufory mieściły się w pamięci i wszystko pięknie hulało. Po przekroczeniu masy krytycznej (a ta nie była wcale duża – jakieś 300 wierszy tabeli), bufory przestały już mieścić się w pamięci i system zaczął je zrzucać na dysk do katalogu tymczasowego. Procesów było wiele, operacje zapisu i odczytu zajmowały dużo czasu i spowodowało to mocne upośledzenie wydajnościowe systemu.

Żeby było śmieszniej, dodanie tych wierszy odbyło się kilkanaście dni przed awarią, a problem objawił się z opóźnieniem, ponieważ bufory były ładowane dopiero przy restarcie wszystkich procesów. Gdybyśmy dodawali te wiersze i zrestartowali serwer od razu – problem ujawniłby się natychmiast i na pewno ktoś wcześniej wpadłby na pomysł sprawdzenia korelacji między tymi zdarzeniami.

Tak więc poprawka błędu okazała się banalna, ale dojście do przyczyny tego błędu wcale już banalne nie było – tak naprawdę na trop błędu naprowadziły nas dopiero niskopoziomowe trace’y procesów unixowych, które wskazały na podejrzane operacje zapisu i odczytu z dysku.

Tyle historii. Historii prostego błędu, poważnych skutków i niezwykłej mobilizacji zespołu, który diagnozował problem. Historia historią, ale wynika z niej kilka bardzo ważnych wniosków.

1. Nie ma czegoś takiego jak „w 100% bezpieczna”  zmiana. Przy obecnym skomplikowaniu i złożoności systemów IT takie historie po prostu będą się zdarzać – będą się zdarzać sytuacje, w której z pozoru niewinna i „w 100% bezpieczna” zmiana (no bo cóż złego może być w dodaniu kilku rekordów do tabeli?!) powoduje nieprzewidziane i bardzo poważne skutki.
2. Refaktoryzuj swój kod! Tak naprawdę rozwiązanie, które spowodowało tę awarię – czyli wczytywanie wszystkich parametrów systemu do wewnętrznego bufora – było niepotrzebne i nadmiarowe. Sześć lat wcześniej jakiś programista popełnił takie rozwiązanie, zobaczył że działa – i zostawił. Zastosowanie wzorca leniwej inicjalizacji (ładowanie do wewnętrznego bufora tylko tych parametrów, które są potrzebne) sprawiłoby, że problem by w ogóle nie powstał. Także nawet jeżeli Twój kod działa poprawnie – zastanów się chwilę, czy nie ma w nim potencjalnych zagrożeń i czy można byłoby go napisać lepiej. Jeżeli możesz coś poprawić – zrób to od razu!
3. Nie ma systemów bez błędów – są systemy, w których błędy nie są widoczne. System działał dość długo na środowisku produkcyjnym – był stabilny i „wygrzany”. A mimo to był w nim bardzo poważny błąd, który spoczywał w uśpieniu przez sześć lat. I żeby było ciekawiej, błąd był w części systemu, której nikt nie dotykał – w wierze, że jest ona stabilnym i dobrze napisanym fragmentem systemu.
4. Wymieniaj doświadczenia. Akcja namierzania przyczyny tego błędu była niesamowitą okazją do wymiany doświadczeń i „podglądania” innych ludzi przy pracy. Czynnikiem, który zadecydował o sukcesie tej akcji, było ściągnięcie bardzo doświadczonych konsultantów z innych firm i posadzenie wszystkich ludzi pracujących nad problemem (administratorów, programistów, konsultantów zewnętrznych…) w jednym dużym pokoju. „Komunikacja osmotyczna”, przerzucanie się ideami i pomysłami, burze mózgów, wspólne rysowanie po tablicy, szybka weryfikacja hipotez i przydział zadań w locie – to wszystko sprawiało, że praca tego zespołu była bardzo efektywna i – co tu dużo kryć – wciągająca. Twierdzę, że zespół pracujący zdalnie, nawet przy zapewnieniu wszelkich możliwych technicznych środków kontaktu, dużo dłużej pracowałby nad tym problemem.
5. Wyciągaj wnioski i staraj się dobrze wykorzystać kryzys. Mimo że cała akcja naprawcza była dość stresująca, to przyniosła ona dużo dobrego. Oprócz wymiany doświadczeń i nauczenia nowych rzeczy, zlokalizowaliśmy też wiele miejsc w systemie, w których można wprowadzić ulepszenia i poprawki.

Cała historia skończyła się dobrze – system wrócił do życia, a deweloperzy wrócili do swojej pracy, bogatsi o nowe doświadczenie.

Ale ile jeszcze takich bomb z opóźnionym zapłonem kryje się w systemach, które tworzymy lub z których z korzystamy?