Pełne CPU Steal na droplecie w DigitalOcean spowodowało prawie 4-godzinną częściową niedostępność strony wpdesk.pl. Zignorowaliśmy pierwsze symptomy, kiedy przez 2 godziny czas ładowania strony znacząco wzrósł. Przez następne półtorej godziny gorączkowo próbowaliśmy znaleźć błąd. Tylko że nie była to nasza wina…
Otwarcie prostej podstrony, szczególnie pierwszego wyniku w Google Ads w Polsce dla frazy “wpdesk inpost”, trwało nawet 90 sekund bez żadnej odpowiedzi serwera.
Pierwszy sygnał o problemie otrzymaliśmy o 13:44 od Grzegorza Roli, który zauważył problem z dostępem do strony po kliknięciu linku w wynikach wyszukiwania Google.
Szybko stwierdziliśmy, że problem dotyczy stron niebuforowanych przez Cloudflare, w tym tych z kampanii Google Ads.
Fałszywe tropy
Strona wpdesk.pl jest chroniona przez proxy Cloudflare, co częściowo złagodziło problem, ale jednocześnie znacznie skomplikowało wykrycie jego przyczyny.
Po sygnale od Grześka cały zespół developerski sprawdził dostępność strony. Tylko jedna osoba odpowiedziała: u mnie działa – Krzysztof Dyszczyk, nasz CEO, który mieszka w Hiszpanii.
Zacząłem podejrzewać, że coś musi być nie tak z ustawieniami w Cloudflare, skoro europejski węzeł (WAW) nie działał, a ten w Hiszpanii serwował stronę poprawnie. Jeszcze tylko jedna sprawa… link od Grześka miał nietypowy parametr zapytania: srsltid… Spróbowałem wejść na stronę, która nie ma tego query. Aha, działa! Czyli to cache.
Zadowolony z szybkiego wykrycia problemu (13:48) sprawdziłem różne dashboardy w Cloudflare. Ruch HTTP, bezpieczeństwo, zablokowane żądania — wszystko w normie. Mimo to coś wciąż nie pasowało. Nie dałem za wygraną, skupiając się na problemie z cache.
Dodałem regułę omijającą parametr query z kluczem cache dla linków z Google Ads, ponieważ ten parametr powodował, że żądania trafiały bezpośrednio do serwera.
Wydawało się to logiczne, ponieważ dział marketingu intensywnie rozwinął ostatnio kampanie reklamowe, co mogło spowodować napływ klientów i przeciążenie serwera.
Problem rozwiązany! Jeszcze tylko rzut oka na ruch w ostatnich dniach…
Co ciekawe, obecny ruch był mniejszy niż w poprzednich dniach. Dlaczego wcześniej wszystko działało poprawnie?
Skoro problem wydawał się być wywołany ominięciem cache, postanowiłem sprawdzić sytuację po stronie serwera. Zauważyłem wtedy, że procesor był wykorzystywany do granic możliwości. PHP-FPM, Redis i cron zużywały wszystkie zasoby, chociaż użycie pamięci RAM i operacje I/O pozostawały w normie.
To nietypowe dla aplikacji PHP, które zazwyczaj są ograniczone właśnie przez I/O (np. odczyt/zapis do dysku, zapytania do bazy danych) lub pamięć (np. wycieki pamięci). Wysokie użycie CPU przy niskim I/O i RAM sugerowało problem z samym kodem PHP (np. nieskończona pętla) lub, jak się później okazało, problem na poziomie infrastruktury.
Zauważyłem jednak, że proces cron samodzielnie zużywał 80% CPU. Stał się on głównym podejrzanym. Tymczasowo go wyłączyłem i sprawdzałem rezultaty w htop.
Widząc, że sytuacja wymyka się spod kontroli, Krzysiek prowadził równoległą analizę. Zauważył wzmożony ruch botów indeksujących. W odpowiedzi na DDoS ze strony crawlerów AI wyłączył dostęp botów do strony. Bezskutecznie.
Cron został wyłączony, boty zablokowane, a PHP nadal zużywał 100% CPU. Zaczęło się robić nerwowo i trudno było o metodyczne podejście. DDoS? Błąd w ostatnim deployu? Backdoor? Wyciek pamięci? Pozostało jeszcze kilka opcji do zweryfikowania, a konta użytkowników i płatności nie działały już od 40 minut.
To musiał być popsuty deploy! Może… gdyby błąd miał miejsce 3 dni wcześniej. Nie pozostawało więcej opcji: hacking. Za namową Grześka, Krzysiek uruchomił tryb Under Attack w Cloudflare (w którym wszystkie żądania przechodzą przez weryfikację JavaScript), żeby ograniczyć ruch na stronie.
Ja sprawdziłem ostatnio modyfikowane pliki i obecność podejrzanych wywołań w kodzie. Dorzuciłem jeszcze lsof, strace i gdb, żeby poczuć się jak prawdziwy SysAdmin.
A próbował Pan włączyć i wyłączyć?
Modyfikacja reguł cache, znaczące ograniczenie ruchu przychodzącego, wielokrotny restart procesów php-fpm i nginx wraz ze zmianami w konfiguracji – wszystkie te działania okazały się nieskuteczne.
Aby upewnić się, że problem nie jest wynikiem działania złośliwego kodu, rozpocząłem ponowne wdrożenie ostatniej wersji strony, co miało na celu usunięcie potencjalnie nadmiarowych plików.
Jednocześnie Krzysiek zdecydował o resecie systemu. sudo reboot… Mija minuta… dwie… sześć. Wciąż nie mogłem zalogować się do konsoli; a podobno to Windows długo się uruchamia.
Nareszcie serwer uruchomił się i niemal natychmiast wrócił do zużycia 100% CPU. Razem z Krzyśkiem zdecydowaliśmy zrobić jeszcze jeden, pełny restart (power cycle), ale powoli traciliśmy już nadzieję.
Po blisko półtoragodzinnej, wydłużającej się walce, o 15:06 zrezygnowaliśmy z debugowania i skupiliśmy się na przywróceniu usługi użytkownikom. Ostatnia kopia zapasowa dropletu była sprzed 4 dni. Baza danych, będąca osobnym serwisem, była nienaruszona.
Pogodziliśmy się z utratą kilku plików z wp-content/uploads. Jednym kliknięciem utworzyłem nowy droplet z kopii zapasowej. Pozostało tylko przepiąć DNS na nowy serwer i…
Strona została przywrócona do działania o 15:21. Zużycie CPU tym razem nie przekraczało normy.
Przebieg zdarzeń
- 11:12 Spike CPU
- 11:52 Pierwsze oznaki problemów
- 11:57 Pierwszy alarm zużycia RAM
- 13:44 Zgłoszenie problemu przez Grześka
- 13:52 Pierwszy reset procesów
- 14:17 Włączenie Under Attack Mode
- 14:30 Drugi reset procesów
- 15:00 Reboot systemu
- 15:11 Utworzenie nowego dropleta z backupu
- 15:21 Przywrócenie strony
Wnioski
Nie spodziewałem się, że infrastruktura, szczególnie u wiodącego dostawcy rozwiązań chmurowych, może samoczynnie prowadzić do krytycznego błędu. Ostatecznie, po kontakcie z pomocą techniczną DigitalOcean, potwierdzono, że przyczyną problemu był CPU Steal. Ze względu na nasz pakiet, który ograniczał czas odpowiedzi wsparcia technicznego do maksymalnie 24 godzin, musieliśmy znaleźć rozwiązanie samodzielnie, tworząc nowy droplet.
Ten incydent sprawił, że po raz pierwszy dowiedziałem się o zjawisku CPU Steal w kontekście wirtualizacji. Oznacza to, że zasoby procesora przydzielone naszemu dropletowi były wykorzystywane przez inne maszyny wirtualne na tym samym hoście fizycznym. To normalny proces, ale zwykle nie przekracza 10% zasobów. W naszym przypadku skradzione zostały wszystkie zasoby CPU.
Wykrycie problemu było utrudnione przez kilka czynników:
- Cloudflare częściowo maskował problem, buforując część ruchu.
- Początkowe objawy (powolne ładowanie stron z Google Ads) wskazywały na problem z cache lub konfiguracją Cloudflare.
- Nasz monitoring nie wykazał wyraźnych sygnałów ostrzegawczych, ponieważ skupiał się na stronach zbuforowanych przez Cloudflare.
Podjęliśmy szereg działań, aby zdiagnozować i rozwiązać problem, w tym:
- Analiza logów serwera (nginx, PHP-FPM, systemowe).
- Wyłączenie crona.
- Zablokowanie botów AI.
- Włączenie trybu “Under Attack” w Cloudflare.
- Modyfikacja reguł cache w Cloudflare.
- Redeploy aplikacji.
- Restart serwera (kilkukrotny).
- Ostatecznie: przywrócenie dropletu z backupu.
Zawiodły nasze procedury monitoringu, co ujawniło luki w naszej konfiguracji i sposobie reagowania. Alerty były skonfigurowane na podstrony buforowane przez Cloudflare, a informacje o zwiększonym zużyciu zasobów zostały zignorowane. Dodatkowo zauważyliśmy, że ruch z reklam omijał cache. Było to szczególnie widoczne, gdy boty próbowały indeksować linki z identyfikatorami śledzenia w URL.
Aby zapobiec podobnym problemom w przyszłości, wprowadziliśmy następujące ulepszenia:
- Monitoring: Skonfigurowaliśmy monitoring tak, aby uwzględniał również ruch omijający cache Cloudflare;
- Cache: Zaktualizowaliśmy reguły cache w Cloudflare, aby uwzględniały parametry URL używane w kampaniach marketingowych.
Doceniamy teraz fakt, że baza danych była odseparowana od plików strony. Bez tego przywrócenie strony do działania nie przebiegłoby tak gładko.
