Wylogowanie, które zabiło klaster
Mój asystent do kodowania przestał odpowiadać. To było całe zgłoszenie błędu.
Model, który za nim stoi, działa na parze małych maszyn NVIDIA DGX Spark pod moim biurkiem — jeden duży model z otwartymi wagami rozłożony na oba GPU, serwowany przez vLLM, osiągalny przez tunel SSH. Kiedy działa, zapominasz, że istnieje. Kiedy przestaje, dostajesz ciszę.
Poszedłem więc szukać, spodziewając się martwego tunelu sieciowego. Wszystko, co sprawdzałem, mówiło, że system jest w porządku.
Akt 1: nadzorca kłamał
Tunel był zdrowy — działał od 22 godzin, oba przekierowania nawiązane. Menedżer klastra był w świetnym humorze:
node_0 Up 46 hours node_1 Up 46 hours
Dwa kontenery, oba żywe, oba z właściwym obrazem. A jednak nic nie odpowiadało na porcie.
Rzecz w tym, że „Up 46 hours” to prawdziwe stwierdzenie o kontenerze i bezwartościowe o usłudze. Kontener to pudełko. Proces w środku był martwy od piętnastu z tych godzin, a pudełku było to obojętne.
Prawdę znał skromny cron. Żeby silnik nie stygł, skrypt co 15 minut go szturcha i loguje przepustowość. Ten log to najdokładniejszy zapis awarii na całej maszynie:
16:30 WARM 700 tokens in 8.4s = 83.6 tok/s
16:45 WARM 700 tokens in 10.1s = 69.2 tok/s <-- below baseline
17:00 SKIP server not responding
... every 15 minutes, all night
Martwy od 16:45. I spójrz na ostatnią udaną linię — 17% wolniej niż poziom bazowy. Nie tylko umarł; już się męczył, minuty wcześniej.
Dziennik systemowy wyjaśnił dlaczego, i nie był subtelny:
low memory! at or below SIGTERM limits: mem 2.00% sending SIGTERM to process "VLLM::Worker": badness 980 escalating to SIGKILL after 1.1 seconds
Zabił go demon braku pamięci. Nie przypadkiem — konfiguracją. Obraz systemu od dostawcy przychodzi z OOM killerem w przestrzeni użytkownika, którego lista preferencji wygląda mniej więcej tak:
--prefer (vllm|VLLM|sglang|llama-server|trtllm|python3|...) --avoid (systemd|sshd|dockerd|containerd|NetworkManager)
Czytaj to jako politykę: serwer inferencji jest wyznaczoną ofiarą; infrastruktura jest chroniona. Całkowicie rozsądne dla stacji roboczej — zachowujesz powłokę, tracisz duży job. Całkowicie błędne dla maszyny, której jedynym celem jest serwowanie tego modelu. Nikt tego nie wybrał. Przyszło w pudełku.
To usterka pierwsza. Zrestartuj i jedziemy dalej, pomyślałem.
Akt 2: restart, który nie chciał
Ponowne uruchomienie zawisło. Węzeł główny normalnie zalogował start, a potem przerwał w pół zdania, na zawsze:
world_size=2 rank=0 distributed_init_method=tcp://<head>:25000 backend=nccl
To rendezvous — miejsce, gdzie rank 0 czeka, aż pojawi się rank 1. Rank 1 nigdy się nie pojawił. Dwadzieścia minut później węzeł główny się poddał z błędem, który nie mówi nic:
RuntimeError: Engine core initialization failed. Failed core proc(s): {}
Pusty zbiór. Z punktu widzenia węzła głównego nic nie zawiodło — coś po prostu nigdy nie dotarło.
Na węźle roboczym nie istniał żaden proces modelu. Jego kontener działał, uruchamiając zaślepkowe polecenie sleep, czekając na job, który umarł zaraz po przybyciu. A logi samego workera? Puste. Narzędzie klastrowe agreguje tylko wyjście węzła głównego, więc ciekawy log był na jedynej maszynie, która milczała.
Prawdziwy traceback był zakopany w kontenerze workera:
File "multiprocessing/synchronize.py", in __setstate__ self._semlock = _multiprocessing.SemLock._rebuild(*state) FileNotFoundError: [Errno 2] No such file or directory
Proces rodzic utworzył nazwany semafor. Proces potomny poszedł go ponownie otworzyć. Już go nie było.
Zły zakręt
Każdy instynkt mówi: pamięć współdzielona. Kontenery plus multiprocessing w Pythonie plus brakujący semafor to „twoja pamięć współdzielona jest za mała” — to najczęstsza odpowiedź na ten traceback w całym internecie.
Sprawdziłem więc. Pamięć współdzielona: 61 GB, całkowicie pusta.
Ślepa uliczka. Tyle że nie — to był trop, tylko przeczytałem go na odwrót. Pytanie nie brzmi, dlaczego pamięć współdzielona była za mała. Brzmi, dlaczego była pusta.
Zwrot akcji
Porównałem obie maszyny:
zawartość pamięci współdzielonej head 3 pliki, najstarszy sprzed czterech dni <-- przetrwał worker (nic) czas katalogu = dokładnie minuta awarii
Ten sam obraz. To samo polecenie. Ten sam użytkownik. Odwrotny wynik.
Różnicą było to, kto był zalogowany.
Większość dystrybucji Linuksa włącza ustawienie systemd o nazwie RemoveIPC. Kiedy kończy się ostatnia sesja logowania użytkownika, niszczy każdy semafor i segment pamięci współdzielonej należący do tego użytkownika. To sprzątanie po interaktywnych logowaniach. Dla długotrwałego joba uruchomionego przez SSH jest katastrofalne.
Do węzła głównego zawsze ktoś był podłączony — mój tunel, moja powłoka — więc jego obiekty pamięci przetrwały dni. Worker dostawał tylko jednorazowe polecenia. A narzędzie klastrowe uruchamia zdalnego workera dokładnie przez takie połączenie: wejdź przez SSH, uruchom, rozłącz się. W chwili rozłączenia kończy się ostatnia sesja użytkownika, a systemd posłusznie usuwa semafory, które worker właśnie utworzył.
narzędzie klastra ──ssh──> worker: start procesu modelu
narzędzie klastra ──exit─> worker: (koniec ostatniej sesji)
│
systemd-logind: „użytkownik się wylogował, sprzątam jego IPC”
│
semafor usunięty
│
proces workera umiera przy następnym spawnie ────> head czeka wiecznie
A potem część, przy której zaśmiałem się na głos: moje własne debugowanie robiło to samo. Każde ssh worker "check something", które uruchamiałem w trakcie startu, było kolejną sesją, której zakończenie mogło wyczyścić pamięć. Śledztwo i usterka były tą samą czynnością.
Poprawka to jedno polecenie na węzeł:
sudo loginctl enable-linger <user>
„Lingering” utrzymuje slice systemd użytkownika przy życiu na stałe, więc „ostatnia sesja się zakończyła” nigdy nie następuje. Kolejne uruchomienie wstało za pierwszym razem. Log rozgrzewania przeskoczył z SKIP na 81 tok/s.
Piętnaście godzin przestoju, naprawione ustawieniem dotyczącym wylogowania.
Akt 3: „to jutro znowu padnie?”
Uczciwe pytanie, a uczciwa odpowiedź brzmiała: nic w przyczynie nie zostało naprawione. Polityka OOM była nietknięta. Poszedłem więc szukać, co faktycznie zjadło pamięć — rzeczy, którą OOM killer oszczędził, strzelając do modelu.
To było drugie środowisko uruchomieniowe modeli na tej samej maszynie, serwujące mniejszy model wewnętrznej usłudze analityki rozmów. Jego konfiguracja zawierała dwie decyzje, które wyglądają niewinnie tylko osobno:
- Aplikacja wywołuje go na żądanie, żeby streszczać nagrane rozmowy.
- Był skonfigurowany, żeby trzymać modele załadowane na zawsze — załadowany model raportował datę wygaśnięcia w roku 2318.
Oś czasu złożyła się co do sekundy:
16:46 rusza zadanie streszczenia; środowisko zaczyna ładować model 14,65 GB 16:51 OOM killer strzela do serwera inferencji 16:51 drugi model kończy się ładować (42 sekundy) 16:52 żądanie streszczenia pada z 500, potem przekracza własny 6-minutowy timeout
Przegrały oba obciążenia. Zadanie, które spowodowało awarię, nawet nie dostało swojego streszczenia.
A pod spodem było cichsze ustalenie. Ponieważ pierwszy serwer już zajmował GPU, drugi model zmieścił na GPU 7 z 51 warstw, a resztę uruchamiał na CPU — na tyle wolno, że pojedyncze żądanie nie mogło się zmieścić w timeoucie wywołującego. Rywalizacja o pamięć od jakiegoś czasu degradowała oba joby, zanim jeden zabiła. Za taką powolność obwinia się wolny job, nigdy rywalizację.
Jeszcze dwie rzeczy, w których się pomyliłem
Pierwsza. Powiedziałem, że zwolnienie bezczynnego modelu odda 14,65 GB RAM. Oddało około 2 GB RAM — i 6 GB swapu. Po 16 godzinach bezczynności na ciasnej maszynie jądro zdążyło już wyrzucić większość na swap. Jeśli dobierasz poprawkę według nominalnego śladu procesu, pomylisz się dokładnie w tym kierunku.
I tak pomogło, ale przez drzwi, na które nie patrzyłem. Ten demon OOM odpala przy koniunkcji — dostępna pamięć poniżej progu i wolny swap poniżej progu. Wolny swap cały czas był poniżej limitu, czyli połowa warunku dotycząca swapu była stale spełniona, a od kuli dzieliła model tylko pamięć. Zwolnienie swapu uzbroiło na nowo zabezpieczenie, o którym nie wiedziałem, że jest wyłączone. Czytaj progi jako warunek logiczny, którym są.
Druga. Oczywistą pozostałą dźwignią było okno kontekstu drugiego modelu. Załadowano go z oknem 32 768 tokenów wyłącznie dlatego, że to maksimum modelu, a nikt niczego nie ustawił — a cache klucz-wartość dla tego okna zajmował 6,4 GB, prawie tyle co sam model o rozmiarze 6,7 GB.
Zmniejszyć, oczywiście. Ale do ilu? Za mało, a długie wejścia zostaną po cichu przycięte — streszczenie wróci wyglądające całkiem normalnie, nigdy nie widząc połowy rozmowy. Oszacowałem więc: tempo mowy, słowa na minutę, tokeny na słowo, z poprawką na język. Wyszło mi, że 8k to ryzyko przy długich rozmowach.
Potem sprawdziłem bazę danych i odkryłem, że aplikacja przez cały czas zapisywała odpowiedź — liczbę tokenów każdego żądania, jakie kiedykolwiek wysłała:
prompt_tokens: min 331 | median 693 | p95 1,796 | max 3,217
Maksimum kiedykolwiek wysłane: 3217 tokenów. Przy oknie 32 768 tokenów. Moje oszacowanie było trzy razy za wysokie, a już miałem odrzucić konfigurację, którą prawdziwe dane spokojnie wspierają.
Każda odpowiedź API zgodnego z OpenAI zawiera blok zużycia tokenów. Większość aplikacji go przechowuje, bo tak prowadzi rozliczenia kosztów. Włożyłem wysiłek w modelowanie liczby, która leżała w tabeli.
Wskazówki dla czytelnika
„Działa” to nie „pracuje”. Nadzorcy kontenerów i procesów odpowiadają na pytanie o żywotność. Jeśli usługa ma stan rozgrzania, kolejkę albo port, pytaj ją.
Najbardziej pouczający log należy do komponentu, który milczy. Kiedy zawiesza się rozproszony job, idź najpierw do cichego węzła. Agregatory pokazują tylko węzeł, który jest jeszcze na tyle zdrowy, żeby logować.
Zawieszenie to nie błąd i nie zostanie zgłoszone jak błąd. Czekanie to właśnie to, co robi rendezvous. Spodziewaj się, że ostateczny komunikat będzie pusty, spóźniony i na złej maszynie.
Sprawdź, kto ustawił politykę OOM, zanim zaczniesz stroić pamięć. Jeśli lista preferencji wymienia twoje obciążenie, ofiarę wybrano na długo przed awarią — i to nie jest proces, który spowodował presję, więc sekcja zwłok zaczyna się od złego trupa.
Uważaj na mechanizmy „sprzątania po wylogowaniu” na maszynach z pracą bez nadzoru. Zakładają, że sesja człowieka wyznacza granice zasobów człowieka. Długotrwałe joby uruchamiane przez SSH bardzo to założenie łamią.
Kiedy twoja technika debugowania jest też wyzwalaczem, możesz gonić błąd w nieskończoność. Jeśli usterka pojawia się tylko wtedy, gdy badasz sprawę, podejrzewaj badanie.
Zanim oszacujesz wielkość, sprawdź, czy system już jej nie zapisuje. Rozliczenia kosztów, logi żądań i kolumny zużycia to pomiary zrobione pod prawdziwym obciążeniem na prawdziwych danych. Twój model obciążenia nim nie jest.
Kiedy oszacowanie i pomiar się różnią, opublikuj oba. Wielkość pomyłki mówi ci, na ile ufać takiemu oszacowaniu następnym razem.
Najgłębsza lekcja jest najmniej techniczna. Dwie niezależne usterki i obie były wartościami domyślnymi — lista preferencji OOM dostawcy i ustawienie sprzątania po wylogowaniu w dystrybucji. Nikt żadnej nie wybrał. Nikt żadnej nie przejrzał. Po prostu tak maszyny przyszły i przez miesiące były rozsądne, aż pewnego popołudnia przestały.
Konfiguracja, której nigdy nie zrobiłeś, nadal jest konfiguracją.