14 września
Czekaliśmy na ten dzień tygodniami. Nasz dostawca proxy rezydencjalnych zamilkł z powodu niezapłaconej faktury jeszcze w lipcu, i przez dwa miesiące coraz większa część naszych 1375 źródeł była crawlowana w sposób zdegradowany albo wcale — fetch'e wygasały z timeoutem, adresy IP były blokowane w połowie sesji, czyli ten rodzaj powolnego krwawienia, które nie objawia się jako awaria, a raczej jako kurcząca się liczba, której nikt nie zauważa, aż staje się to żenujące. Odnowiliśmy pulę. Nowa pula, 20 000 rotujących linii sesji rezydencjalnych, każdy exit sprawdzony sondą przed dopuszczeniem w pobliże produkcji. 100% sondowań przeszło. AE, DE, JP — wszystkie działają, wszystkie czyste.
Przeprowadziliśmy więc nadzorowany crawl, taki, w którym ktoś faktycznie obserwuje dashboard, a nie powierza wszystko crontabowi. Oczekiwałem dokładnego przeciwieństwa katastrofy.
Dostaliśmy bazę danych, która w jednym przebiegu straciła 84 401 wierszy, przy czym 102 źródła spadły o ponad 25% względem poprzedniego zrzutu. Gorzej niż te dwa miesiące głodu proxy, które właśnie naprawiliśmy.
Błędna teoria, w skrócie
Moim pierwszym odruchem — i otwarcie się do tego przyznam — było podejrzenie, że nowa pula jest w jakiś sposób gorsza, niż wskazywała sonda. Może adresy IP sesji były ograniczane przez rate-limiting w trakcie crawlu w sposób, którego jednorazowa sonda by nie wychwyciła. To rozsądna teoria. Jest też błędna, a wiara w nią choćby przez pół dnia kosztowała nas czas, którego nie mieliśmy, bo cron crawlowania pozostaje wstrzymany przez cały czas debugowania takiej teorii — nie chce się, żeby zły przebieg nadpisał dobry zrzut, póki wciąż się zgaduje.
Sygnałem, który obalił tę teorię, było dubizzle. Jedno z naszych najbardziej obszernych źródeł z ZEA w tym przebiegu faktycznie pobrało 32 595 ogłoszeń — liczba całkowicie zdrowa, proxy ewidentnie działały — a następnie odrzuciło prawie wszystkie z nich. Nie nieudany fetch. Pobrane, a potem wyrzucone.
16 września: znalezienie właściwego błędu
To właśnie wtedy przestała to być historia o proxy i stała się historią o zastępowaniu wierszy. Nasza warstwa trwałości zapisuje każde źródło jako pełne nadpisanie <site>_cars_for_sale.csv przy każdym przebiegu — tylko aktualne ogłoszenia, zastąp całą tabelę. To zachowanie prawidłowe, gdy crawl się kończy. Katastrofalne, gdy crawl wygasa z timeoutem w połowie, a scraper zapisuje to, co zdążył zebrać w częściowej partii, jakby to był kompletny zrzut. Źródło, które normalnie zawiera 9000 aktywnych ogłoszeń, zostaje nadpisane 1200, które zescrapowano przed upływem czasu, a pozostałe 7800 znika — nie dlatego, że samochody się sprzedały, ale dlatego, że nasz własny kod zdecydował, że niekompletny fetch jest kompletny.
Proxy nas nie okłamywały. Problemem była logika powtórzeń (retry), która po cichu była wadliwa od dawna, po prostu maskowana przez zdrowszą pulę, która dawniej kończyła fetch'e zanim ta zamiana miała jakiekolwiek znaczenie.
Oto, co ta zamiana faktycznie kosztowała, kiedy już zrobiliśmy obliczenia:
| Stary mechanizm powtórzeń | Naprawiony mechanizm | |
|---|---|---|
| Powtórzenia na proxy | 3 | 1 |
| Opóźnienie na próbę | 1s | — |
| Efektywny limit przy puli 50 proxy | ~56 minut na URL | budżet całkowity 120 sekund |
| Zachowanie przy timeout | zapisuje częściową partię jako pełny zrzut | źródło pomijane, zachowany poprzedni zrzut |
Pięćdziesiąt sześć minut, by poddać się przy jednym URL-u. Przemnóżcie to przez crawl obejmujący ponad tysiąc źródeł i dostajecie właśnie ten rodzaj cichej, nierównomiernie rozłożonej awarii, który zaobserwowaliśmy — część źródeł w porządku, 102 z nich wypatroszone, a w logach nic nie krzyczy "awaria proxy", bo technicznie żadnej awarii nie było.
25 września: naprawa i część, która ma znaczenie dla was
Łatka, która trafiła na produkcję dziewięć dni później, zrobiła dwie niespektakularne rzeczy. Ograniczyła matematykę powtórzeń, tak by zawieszony fetch poddawał się szybko, zamiast zjadać prawie godzinę, oraz — to ta część, która faktycznie zapobiega utracie danych — częściowy fetch nie zastępuje już pełnego zbioru wierszy. Jeśli źródło zdąży pobrać tylko 1200 ze swoich zwykłych 9000 ogłoszeń, zachowujemy poprzedni kompletny zrzut, zamiast nadpisywać go fragmentem. Tego samego dnia wprowadzono drugą zmianę, która zapisuje widoczną flagę CRAWL_PAUSED, sprawdzaną przez nasz monitoring przed wysłaniem komukolwiek alertu o spadku — dzięki czemu celowa pauza odczytywana jest jako pauza, a nie alarm.
Czemu czytelnik szukający używanej Hyundai powinien się tym w ogóle interesować? Bo oznaczenia "poniżej rynku", które publikujemy — 12 823 z nich aktywne na stronie w tym tygodniu — są uczciwe tylko wtedy, gdy kohorta, z którą porównujemy ogłoszenie, to rzeczywisty, kompletny rynek regionalny, a nie fragment obcięty przez timeout. Plakietka "deal" zbudowana na zrzucie, który stracił trzy czwarte zbioru porównawczego, nie jest plakietką okazji — to szum w zielonej etykietce. Woleliśmy wstrzymać crawl na dziewięć dni, niż to opublikować.
Dzisiejszy zbiór danych to 1 108 535 ogłoszeń z 73 regionów i 1375 źródeł — większy, niż był przed całą tą historią, z odnowionymi proxy i zamkniętym błędem zastępowania wierszy. Ale liczba, do której wciąż wracam, to nie suma całkowita. To 84 401 — różnica między crawlem, który na poziomie proxy wyglądał zdrowo, a takim, który faktycznie taki był.
