„Kubernetes zwiększył opóźnienie dziesięciokrotnie”: kto jest temu winny?

Przyp. tłum.: Ten artykuł, napisany przez Galo Navarro, który pełni funkcję Głównego Inżyniera Oprogramowania w europejskiej firmie Adevinta, to fascynujące i pouczające "śledztwo" dotyczące eksploatacji infrastruktury. Jego oryginalny tytuł został nieco zmieniony w tłumaczeniu z powodu wyjaśnienia, które autor podaje na początku.

Notatka od autora: Wygląda na to, że ten post przyciągnął znacznie więcej uwagi, niż się spodziewano. Wciąż otrzymuję gniewne komentarze na temat tego, że tytuł artykułu wprowadza w błąd i że niektórzy czytelnicy są rozczarowani. Rozumiem powody tego, co się dzieje, dlatego, niezależnie od ryzyka, że mogę zepsuć całą intrygę, chcę od razu powiedzieć, o czym jest ten artykuł. Podczas przechodzenia zespołów na Kubernetes zauważam ciekawą rzeczą: za każdym razem, gdy pojawia się problem (na przykład wzrost opóźnień po migracji), pierwszy w kolejności jest Kubernetes, jednak okazuje się, że orkiestrator, w zasadzie, nie jest winny. Ten artykuł opowiada o jednym z takich przypadków. Jego tytuł powtarza wykrzyknienie jednego z naszych programistów (później przekonasz się, że Kubernetes nie ma tu nic do rzeczy). Nie znajdziesz w nim niespodziewanych odkryć na temat Kubernetes, ale możesz liczyć na kilka dobrych lekcji o złożonych systemach.

Kilka tygodni temu nasz zespół zajmował się migracją jednego mikroserwisu na główną platformę, obejmującą CI/CD, środowisko robocze oparte na Kubernetes, metryki i inne przydatne narzędzia. Migracja miała charakter próbny: planowaliśmy użyć go jako bazy i przenieść jeszcze około 150 serwisów w najbliższych miesiącach. Wszystkie one odpowiadają za funkcjonowanie niektórych z największych platform internetowych w Hiszpanii (Infojobs, Fotocasa itd.).

Po tym, jak wdrożyliśmy aplikację w Kubernetes i przekierowaliśmy na nią część ruchu, czekała nas niepokojąca niespodzianka. Opóźnienie latencji żądań w Kubernetes było dziesięciokrotnie wyższe niż w EC2. W zasadzie trzeba było albo znaleźć rozwiązanie tego problemu, albo zrezygnować z migracji mikroserwisu (i być może całego projektu).

Dlaczego w Kubernetes opóźnienie jest tak znacznie wyższe niż w EC2?

Aby znaleźć wąskie miejsce, zebraliśmy metryki na całej drodze żądania. Nasza architektura jest prosta: API Gateway (Zuul) przekazuje żądania do instancji mikroserwisu w EC2 lub Kubernetes. W Kubernetes używamy NGINX Ingress Controller, a backendy stanowią zwykłe obiekty typu Deployment z aplikacją JVM na platformie Spring.

                                  EC2
                            +---------------+
                            |  +---------+  |
                            |  |         |  |
                       +-------> BACKEND |  |
                       |    |  |         |  |
                       |    |  +---------+  |                   
                       |    +---------------+
             +------+  |
Public       |      |  |
      -------> ZUUL +--+
traffic      |      |  |              Kubernetes
             +------+  |    +-----------------------------+
                       |    |  +-------+      +---------+ |
                       |    |  |       |  xx  |         | |
                       +-------> NGINX +------> BACKEND | |
                            |  |       |  xx  |         | |
                            |  +-------+      +---------+ |
                            +-----------------------------+

Wydawało się, że problem był związany z opóźnieniem na wczesnym etapie działania w backendzie (oznaczyłem problematyczny obszar na wykresie jako „xx”). W EC2 czas odpowiedzi aplikacji wynosił około 20 ms. W Kubernetes opóźnienie wzrastało do 100—200 ms.

Szybko odrzuciliśmy prawdopodobnych podejrzanych związanych ze zmianą środowiska wykonawczego. Wersja JVM pozostała niezmieniona. Problemy z konteneryzacją również nie miały znaczenia: aplikacja już wcześniej działała pomyślnie w kontenerach w EC2. Obciążenie? Obserwowaliśmy wysokie opóźnienia nawet przy 1 żądaniu na sekundę. Odstępów na zbieranie śmieci też nie można było zlekceważyć.

Jeden z naszych administratorów Kubernetes zapytał, czy aplikacja ma zewnętrzne zależności, ponieważ w przeszłości żądania do DNS powodowały podobne problemy.

Hipoteza 1: Rozwiązywanie nazw DNS

Przy każdym żądaniu nasza aplikacja zwraca się od jednego do trzech razy do instancji AWS Elasticsearch w domenie podobnej do elastic.spain.adevinta.com. W kontenerach mamy shella, więc możemy sprawdzić, czy rzeczywiście wyszukiwanie domeny zajmuje dużo czasu.

Zapytania DNS z kontenera:

[root@be-851c76f696-alf8z \/]# while true; do dig "elastic.spain.adevinta.com" | grep time; sleep 2; done
;; Query time: 22 msec
;; Query time: 22 msec
;; Query time: 29 msec
;; Query time: 21 msec
;; Query time: 28 msec
;; Query time: 43 msec
;; Query time: 39 msec

Podobne zapytania z jednej z instancji EC2, na której działa aplikacja:

bash-4.4# while true; do dig "elastic.spain.adevinta.com" | grep time; sleep 2; done
;; Query time: 77 msec
;; Query time: 0 msec
;; Query time: 0 msec
;; Query time: 0 msec
;; Query time: 0 msec

Biorąc pod uwagę, że wyszukiwanie zajmuje około 30 ms, stało się oczywiste, że rozwiązywanie DNS przy dostępie do Elasticsearch rzeczywiście przyczynia się do wzrostu opóźnienia.

Jednak to było dziwne z dwóch powodów:

1. Mamy już wiele aplikacji w Kubernetes, które współdziałają z zasobami AWS, ale nie cierpią z powodu dużych opóźnień. Jaka by nie była przyczyna, dotyczy ona konkretnie tego przypadku.
2. Wiemy, że JVM wykonuje pamięciowe buforowanie DNS. W naszych obrazach wartość TTL jest zapisana w $JAVA_HOME/jre/lib/security/java.security i ustawiona na 10 sekund: networkaddress.cache.ttl = 10. Innymi słowy, JVM powinna buforować wszystkie zapytania DNS przez 10 sekund.

Aby potwierdzić pierwszą hipotezę, zdecydowaliśmy na czas zrezygnować z wywołań do DNS i zobaczyć, czy problem zniknie. Najpierw postanowiliśmy przeorganizować aplikację, aby łączyła się z Elasticsearch bezpośrednio przez adres IP, a nie przez nazwę domeny. Wymagałoby to zmian w kodzie i nowego wdrożenia, więc po prostu przypisaliśmy domenę do jej adresu IP w /etc/hosts:

34.55.5.111 elastic.spain.adevinta.com

Teraz kontener otrzymywał IP prawie natychmiast. Doprowadziło to do pewnej poprawy, ale tylko nieco zbliżyliśmy się do oczekiwanego poziomu opóźnienia. Choć rozwiązywanie DNS zajmowało dużo czasu, rzeczywista przyczyna nadal umykała naszemu zrozumieniu.

Diagnostyka za pomocą sieci

Zdecydowaliśmy się przeanalizować ruch z kontenera za pomocą tcpdump, aby zobaczyć, co dokładnie dzieje się w sieci:

[root@be-851c76f696-alf8z /]# tcpdump -leni any -w capture.pcap

Następnie wysłaliśmy kilka zapytań i pobraliśmy ich zrzut (kubectl cp my-service:/capture.pcap capture.pcap) do dalszej analizy w Wireshark.

W zapytaniach DNS nie było nic podejrzanego (oprócz jednej drobnej rzeczy, o której opowiem później). Ale były pewne dziwności w tym, jak nasza usługa obsługiwała każde zapytanie. Poniżej znajduje się zrzut ekranu z zrzutu, pokazujący przyjęcie zapytania przed rozpoczęciem odpowiedzi:

Numery pakietów podano w pierwszej kolumnie. Dla jasności podświetliłem kolorami różne strumienie TCP.

Zielony strumień, zaczynający się od 328. pakietu, pokazuje, jak klient (172.17.22.150) nawiązał połączenie TCP z kontenerem (172.17.36.147). Po wstępnym uzgodnieniu (328-330), pakiet 331 przyniósł HTTP GET /v1/.. — przychodzące zapytanie do naszej usługi. Cały proces zajął 1 ms.

Szary strumień (od pakietu 339) pokazuje, że nasza usługa wysłała zapytanie HTTP do instancji Elasticsearch (brak uzgodnienia TCP, ponieważ używane jest już istniejące połączenie). Zajęło to 18 ms.

Jak na razie wszystko jest w porządku, a czasy mniej więcej odpowiadają oczekiwanym opóźnieniom (20-30 ms przy pomiarach z klienta).

Jednak niebieska sekcja zajmuje 86 ms. Co się tam dzieje? Z pakietem 333 nasza usługa wysłała żądanie HTTP GET na /latest/meta-data/iam/security-credentials, a zaraz po nim, przez to samo połączenie TCP, kolejne żądanie GET na /latest/meta-data/iam/security-credentials/arn:...

Zauważyliśmy, że to powtarza się przy każdym żądaniu w całej trasie. Rozwiązanie DNS rzeczywiście trwa trochę dłużej w naszych kontenerach (wyjaśnienie tego zjawiska jest dość interesujące, ale zostawię je na osobny artykuł). Okazało się, że przyczyną dużych opóźnień są wywołania do serwisu AWS Instance Metadata przy każdym żądaniu.

Hipoteza 2: niepotrzebne wywołania do AWS

Oba endpointy należą do AWS Instance Metadata API. Nasz mikroserwis korzysta z tej usługi podczas pracy z Elasticsearch. Oba wywołania są częścią podstawowego procesu autoryzacji. Endpoint, do którego następuje wywołanie podczas pierwszego żądania, zwraca rolę IAM związaną z instancją.

/ # curl http://169.254.169.254/latest/meta-data/iam/security-credentials/
arn:aws:iam::<account_id>:role/some_role

Drugie żądanie zwraca się do drugiego endpointu o tymczasowe uprawnienia dla danej instancji:

/ # curl http://169.254.169.254/latest/meta-data/iam/security-credentials/arn:aws:iam::<account_id>:role/some_role`
{
    "Code" : "Success",
    "LastUpdated" : "2012-04-26T16:39:16Z",
    "Type" : "AWS-HMAC",
    "AccessKeyId" : "ASIAIOSFODNN7EXAMPLE",
    "SecretAccessKey" : "wJalrXUtnFEMI/K7MDENG/bPxRfiCYEXAMPLEKEY",
    "Token" : "token",
    "Expiration" : "2017-05-17T15:09:54Z"
}

Klient może korzystać z nich przez krótki czas i okresowo musi uzyskiwać nowe certyfikaty (do ich Wygaśnięcie). Model jest prosty: AWS przeprowadza częstą rotację tymczasowych kluczy z względów bezpieczeństwa, ale klienci mogą je cache'ować na kilka minut, rekompensując spadek wydajności związany z uzyskiwaniem nowych certyfikatów.

AWS Java SDK powinno zająć się organizacją tego procesu, jednak z jakiegoś powodu tak się nie dzieje.

Przeszukując problemy na GitHubie, natknęliśmy się na problem #1921. Pomogło nam to określić kierunek, w którym należy "kopać" dalej.

AWS SDK aktualizuje certyfikaty po wystąpieniu jednego z następujących warunków:

• Termin wygaśnięcia ich ważności (Wygaśnięcie) przypada na EXPIRATION_THRESHOLD, twardo ustalony w kodzie na 15 minut.
• Od ostatniej próby aktualizacji certyfikatów minęło więcej czasu niż REFRESH_THRESHOLD, 'hardcode' na 60 minut.

Aby sprawdzić faktyczny termin wygaśnięcia uzyskiwanych przez nas certyfikatów, wykonaliśmy powyższe polecenia cURL zarówno z kontenera, jak i z instancji EC2. Czas ważności certyfikatu uzyskanego z kontenera okazał się znacznie krótszy: dokładnie 15 minut.

Teraz wszystko jest jasne: dla pierwszego żądania nasza usługa otrzymywała tymczasowe certyfikaty. Ponieważ ich ważność nie przekraczała 15 minut, przy kolejnych żądaniach AWS SDK postanawia je zaktualizować. Tak się działo przy każdym żądaniu.

Dlaczego czas ważności certyfikatów stał się krótszy?

Usługa AWS Instance Metadata jest przeznaczona do pracy z instancjami EC2, a nie Kubernetes. Z drugiej strony, nie chcieliśmy zmieniać interfejsu aplikacji. W tym celu skorzystaliśmy z KIAM — narzędzia, które za pomocą agentów na każdym węźle Kubernetes, pozwala użytkownikom (inżynierom wprowadzającym aplikacje do klastra) przydzielać role IAM kontenerom w podach tak, jakby były instancjami EC2. KIAM przechwytuje wywołania do usługi AWS Instance Metadata i obsługuje je z własnej pamięci podręcznej, wcześniej uzyskując je od AWS. Z perspektywy aplikacji nic się nie zmienia.

KIAM dostarcza krótkoterminowe certyfikaty do podów. Jest to rozsądne biorąc pod uwagę, że średni czas życia poda jest krótszy niż instancji EC2. Domyślnie czas ważności certyfikatów wynosi te same 15 minut.

W rezultacie, jeśli nałożymy oba domyślne wartości na siebie, powstaje problem. Każdy certyfikat dostarczony aplikacji wygasa po 15 minutach. W tym czasie AWS Java SDK wymusza aktualizację każdego certyfikatu, którego czas ważności wynosi mniej niż 15 minut.

W rezultacie tymczasowy certyfikat jest wymuszony do aktualizacji przy każdym żądaniu, co prowadzi do kilku wywołań API AWS i znaczącego zwiększenia opóźnienia. W AWS Java SDK odkryliśmy feature request, w którym wzmiankowano o podobnym problemie.

Rozwiązanie okazało się proste. Po prostu przestawiliśmy KIAM na żądanie certyfikatów o dłuższym czasie ważności. Gdy to nastąpiło, żądania zaczęły przebiegać bez udziału usługi AWS Metadata, a opóźnienie spadło nawet poniżej poziomu EC2.

Wnioski

Na podstawie naszego doświadczenia z migracjami można powiedzieć, że jednym z najczęstszych źródeł problemów są nie błędy w Kubernetes czy innych elementach platformy. Nie jest to również związane z żadnymi fundamentalnymi wadami w mikrousługach, które przenosimy. Problemy często występują po prostu dlatego, że łączymy różne elementy.

Mieszamy złożone systemy, które nigdy wcześniej nie współdziałały ze sobą, mając nadzieję, że razem stworzą jedną, większą całość. Niestety, im więcej elementów, tym więcej miejsca na błędy, tym wyższa entropia.

W naszym przypadku wysoka latencja nie była wynikiem błędów lub złych decyzji w Kubernetes, KIAM, AWS Java SDK czy w naszej mikrousłudze. Była efektem połączenia dwóch niezależnych parametrów, ustawionych domyślnie: jednego w KIAM, drugiego w AWS Java SDK. Osobno oba parametry mają sens: zarówno aktywna polityka aktualizacji certyfikatów w AWS Java SDK, jak i krótki czas ważności certyfikatów w KIAM. Ale po złączeniu ich wyniki stają się nieprzewidywalne. Dwa niezależne i logiczne rozwiązania wcale nie muszą mieć sensu po połączeniu.

P.S. od tłumacza

Aby dowiedzieć się więcej o architekturze narzędzia KIAM do integracji AWS IAM z Kubernetes, można przeczytać w w tym artykule od jego twórców.

A na naszym blogu przeczytaj także:

• «3 historie awarii Kubernetes w produkcji: anti-affinity, graceful shutdown, webhook»;
• «Jak priorytety podów w Kubernetes spowodowały przestój w Grafana Labs»;
• «6 interesujących błędów systemowych podczas korzystania z Kubernetes [i ich rozwiązanie]»;
• «6 praktycznych historii z naszych dni SRE».

Źródło: habr.com