AI w triage flake'ów - hipotezy, nie werdykt (lipiec 2023)

Czerwony nocny przebieg i karta z czatem

Jest 15 lipca. Rano patrzę na raport z nocnego przebiegu, widzę jeden czerwony test i wiem z góry, że najprawdopodobniej nie zobaczę go dzisiaj drugi raz. To jest ta klasa wyniku, przy której człowiek klika “re-run”, dostaje zielone i wraca do swoich rzeczy, a po trzech tygodniach nikt już nie czyta rannego raportu.

Flake nie zniknął mi z pipeline’u przez to, że od pół roku mam otwartą kartę z czatem. Zniknęła natomiast wymówka, że nie mam z kim pogadać o logu o siódmej trzydzieści. I dokładnie o to chcę zapytać w tym wpisie: czy model skraca mi ten pierwszy, najbardziej głupi etap triage’u, w którym muszę zdecydować, do którego z czterech koszyków wrzucam awarię. Test jest zły. Dane są złe. Infrastruktura miała zły dzień. Produkt jest zepsuty.

Ten pierwszy podział decyduje o wszystkim, co dzieje się potem, bo wyznacza, kto dostaje ticket i ile czasu na to poświęcam. Jest też etapem, na którym najłatwiej się pomylić w najdroższą stronę: uznać za “środowisko” coś, co jest błędem produktu, i zamknąć sprawę restartem joba.

Od 6 do 14 lipca prowadziłem notes. Każdy czerwony przebieg, którego nie rozumiałem w pierwszych trzydziestu sekundach, przepuszczałem przez model, zapisywałem hipotezy, które dostałem, i to, co się z nimi stało po próbie odtworzenia. Wyszło 11 przebiegów i 33 hipotezy, po trzy na przebieg. To jest notes jednej osoby z dziewięciu dni, nie badanie, i tak będę o tym pisał.

Stan narzędzi na ten tydzień ustalam od razu, bo za pół roku nikt nie będzie pamiętał, co było za bramką. GPT-4 mam w ChatGPT Plus w przełączniku modelu od marca i to tam wykonuję całą pracę z tego wpisu. Od 6 lipca gpt-4 jest w API dostępne bez waitlisty dla płacących klientów, czyli pierwszy raz mógłbym to oskryptować; nie zrobiłem tego i w sekcji o warsztacie wyjaśnię, dlaczego. Czat Copilota mam od maja, kiedy zszedłem z waitlisty i otworzyłem go w VS Code Insiders, i nadal jest to technical preview: osobna instalacja edytora plus rozszerzenie Nightly. Do triage’u flake’ów go nie używam, bo czat w edytorze widzi otwarty plik, a nie log z nocnego przebiegu; cała praca z tego wpisu dzieje się w Plus. Publicznej bety dla organizacji na Copilot Business w dniu tego wpisu jeszcze nie ma, a o GA nikt nawet nie mówi. 11 lipca Anthropic ogłosił Claude 2 i zostawiam to przy jednym zdaniu, bo nie przepuściłem przez niego ani jednego własnego loga. Runner mam świeży: Playwright 1.36.1 z 14 lipca, czyli z wczoraj.

Czego tu nie będzie. Nie będzie narzędzia, które samo naprawia selektor, nie będzie modelu podpiętego pod CI i nie będzie niczego, co samo zakłada albo zamyka zgłoszenie. Model w tym wpisie robi dokładnie jedną rzecz: produkuje listę rzeczy do sprawdzenia. Sprawdzam ja.

Co wklejam do czatu

Wklejam cztery rzeczy i wypracowałem sobie tę listę metodą prób, bo pierwsze rozmowy prowadziłem tak, że wrzucałem cały log przebiegu i pytałem “co jest nie tak”.

Pierwsza rzecz to pełna nazwa testu razem z plikiem i numerem linii. Bez tego model nie ma pojęcia, czy patrzy na test jednostkowy, integracyjny czy przeglądarkowy, i domyśla się z komunikatów, zwykle źle.

Druga to fragment logu, nie cały log. Trzydzieści do sześćdziesięciu linii wokół miejsca awarii, z sekcją logs Playwrighta, kawałkiem kodu, który raportuje sam runner, i listą załączników. Nagłówek przebiegu z listą czterdziestu zielonych testów nie wnosi nic poza tokenami.

Trzecia to miejsce w pipelinie, i to jest informacja, o której najczęściej się zapomina. Awaria na bramce pull requesta i awaria w nocnym przebiegu to u mnie dwa różne światy, bo mają inne zależności i inne środowisko. Podział na koszyki po triggerze opisałem we wrześniu przy strategii testów w CI/CD i to on jest tu kontekstem: bramka bierze jednostki, kontrakty i jeden smoke, noc bierze pełne E2E. Model nie ma jak tego wiedzieć, więc piszę mu wprost, w którym koszyku jestem.

Czwarta to jedno zdanie o tym, co było w commicie. Zwykle brzmi ono “commit nie dotykał ani tego testu, ani tej funkcji”, bo gdyby dotykał, nie prowadziłbym triage’u, tylko czytał diff.

Do tego dochodzi redakcja i to nie jest formalność, bo log z CI jest pełen rzeczy, których nie wolno wynosić. Wycinam tokeny i nagłówki Authorization, adresy wewnętrznych usług i nazwy agentów, adresy artefaktów z podpisem w query stringu, prawdziwe adresy e-mail użytkowników testowych, identyfikatory zamówień i wszystko, co mogłoby wskazać, czyj to projekt. Zasada jest ta sama, którą zapisałem w marcu przy GPT-4 i szkicowaniu przypadków: wklejenie cudzego artefaktu do zewnętrznej usługi jest decyzją właściciela tego artefaktu, nie moją. Kiedy po redakcji zostaje mi log, z którego nic nie wynika, to znaczy, że tej awarii nie triage’uję w czacie.

Nie mam też miejsca, w którym ustawiłbym ten kontekst raz na zawsze. Trzymam więc trzy akapity w pliku docs/triage-prompt.md w repozytorium i wklejam je na początku każdej rozmowy: mój stack, moje piny wersji, zakaz proponowania poprawek w pierwszej odpowiedzi. Struktura promptu jest ta sama, którą rozpisałem w lutym, tylko wejściem jest log, a nie specyfikacja.

Jedna uwaga o modelu. Do tego zadania gpt-3.5-turbo mi nie wystarcza i sprawdziłem to dwa razy. Przy sześćdziesięciu linijkach logu zaczyna komentować pierwszą trzecią i gubi to, co jest na końcu, czyli akurat sekcję z załącznikami i podsumowanie przebiegu. GPT-4 w Plus trzyma cały wklejony blok i to jest ta sama różnica, którą opisywałem w marcu przy długiej specyfikacji. Limit wiadomości w Plus przy triage’u nie boli, bo to nie jest praca polegająca na dwudziestu pytaniach pod rząd.

Trzy hipotezy zamiast jednego werdyktu

Pokażę jeden przebieg w całości, bo bez tego cała reszta jest opowieścią o wrażeniach.

Log poniżej pochodzi z mojego własnego repozytorium z przykładami na blog, nie z żadnego projektu klienta. Nazwy testu, selektorów i kodu rabatowego podmieniłem na te z wymyślonego sklepu, którego użyłem w marcu, żeby nie mieszać dwóch światów. Kształt, komunikaty i czasy są takie, jakie wypisał runner.

Running 40 tests using 4 workers

  1) [chromium] › cart/coupon.spec.ts:41:3 › koszyk › nalicza rabat po zastosowaniu kodu

    TimeoutError: locator.click: Timeout 15000ms exceeded.
    =========================== logs ===========================
    waiting for getByTestId('apply-coupon')
      locator resolved to <button disabled data-testid="apply-coupon">Zastosuj</button>
    attempting click action
      waiting for element to be visible, enabled and stable
        element is not enabled
      retrying click action, attempt #2
      waiting for element to be visible, enabled and stable
        element is not enabled
    ============================================================

      39 |     await cart.open()
      40 |     await cart.couponInput.fill('SUMMER10')
    > 41 |     await cart.applyCoupon.click()
         |                            ^
      42 |     await expect(cart.total).toHaveText('90,00 zł')

    attachment #1: trace (application/zip) ----------------------
    test-results/cart-coupon-nalicza-rabat-chromium/trace.zip
    ------------------------------------------------------------

  1 failed
    [chromium] › cart/coupon.spec.ts:41:3 › koszyk › nalicza rabat po zastosowaniu kodu
  39 passed (2.4m)

Prompt wyglądał tak:

Jestem inżynierem QA. Poniżej log jednego czerwonego testu z Playwrighta 1.36.1,
TypeScript, 4 workery, przebieg nocny, nie bramka pull requesta. Commit w tym
przebiegu nie dotykał ani tego testu, ani koszyka.

Nie podawaj jednej przyczyny. Podaj 3 hipotezy uporządkowane od najbardziej do
najmniej prawdopodobnej. Do każdej dopisz: jak ją odtworzę lokalnie, co zobaczę
jeśli jest prawdziwa, co zobaczę jeśli jest fałszywa.
Nie proponuj poprawek w tej odpowiedzi. Nie zakładaj kodu, którego nie ma w logu.

Dostałem trzy hipotezy w tej kolejności:

1. Wyścig o środowisko na agencie. Cztery workery rozmawiają z jedną instancją aplikacji pod jednym portem, więc jeden worker widzi koszyk drugiego, a przycisk jest wyłączony, bo w tym koszyku kod rabatowy już siedzi.
2. Współdzielony fixture danych. Kod SUMMER10 jest zasobem wspólnym dla całego zestawu, a nie danymi tego testu. Ktoś go zużył pierwszy i walidacja po stronie serwera trzyma przycisk wyłączony.
3. retries w konfiguracji maskują to od tygodni. Ten sam problem występuje też na bramce, tylko druga próba wychodzi na zielono, więc nikt go nie widzi.

To jest dobra lista. Jest też lista, której nie wolno przeczytać jako werdyktu, i pokazuje to każdy z trzech punktów po kolei.

Hipoteza pierwsza, ta postawiona jako najbardziej prawdopodobna, padła w pierwszym podejściu. Odpaliłem ten sam test na jednym workerze, na własnym porcie i we własnym projekcie Compose, dokładnie tak jak dzielę środowiska na plasterki od października 2021, i puściłem go dwadzieścia razy pod rząd. Padł. Nie raz, a sześć razy, i co ważniejsze: wyłącznie w ostatnich sześciu przebiegach. Skoro pada bez żadnej równoległości, to równoległość nie jest przyczyną, a cała atrakcyjna opowieść o wyścigu dwóch workerów o jeden port jest nieprawdziwa. Model postawił ją pierwszą, bo wyścig przy czterech workerach brzmi prawdopodobnie, a nie bo cokolwiek w logu na niego wskazuje.

Hipoteza trzecia zginęła jeszcze szybciej i nawet nie wymagała uruchamiania. Ten test w ogóle nie wchodzi na bramkę: bramka bierze jednostki, kontrakty i jeden smoke, a cart/coupon.spec.ts jest wyłącznie w nocnym zestawie, więc nie ma tam żadnej zielonej drugiej próby, która cokolwiek maskuje. Że jestem w nocnym przebiegu, a nie na bramce, napisałem modelowi w prompcie wprost i mimo tego dostałem bramkę w hipotezie. W samym nocnym projekcie retries stoi na zerze od dnia, w którym ten plik konfiguracyjny powstał, i widać to w historii playwright.config.ts: ponowne przebiegi robi u mnie rano człowiek klikający “re-run”, nie runner. Dwie minuty, jeden rzut okiem, hipoteza z listy. To zresztą najlepszy typ podpowiedzi, jaki dostaję: nie ta, która jest trafna, ale ta, którą da się wykluczyć taniej niż przez odtwarzanie.

Hipoteza druga trafiła w kategorię i całkowicie rozminęła się z mechanizmem. Dane rzeczywiście były przyczyną, ale nie tak, jak napisał model. SUMMER10 jest w moich danych zasilających kodem z licznikiem użyć, ustawionym na dwadzieścia. Lokalny Compose podnoszę z tego samego zrzutu co trwałe środowisko nocne, więc licznik przyjechał do mnie już nadgryziony i zostało w nim czternaście użyć. Nikt go nie zużywa “pierwszy” w wyścigu; on się po prostu wyczerpuje przez kolejne przebiegi i nic go nie zeruje. Dlatego padło sześć razy na końcu, a nie losowo w środku, i dlatego kolejność wyników w moim --repeat-each była informacją ważniejszą od samego faktu porażki.

Ostatni krok zrobiłem bez modelu i to jest sedno tego wpisu. Zapytałem, dlaczego licznik wyczerpuje się właśnie w nocnym zestawie, i odpowiedź miałem u siebie, w podziale na koszyki: joby za bramką stawiają swoje zależności w kontenerach na czas joba, dokładnie tak jak opisywałem w listopadzie 2021 przy Testcontainers na Azure Pipelines, więc każdy z nich startuje ze świeżym licznikiem i żaden nie zdąży go nadgryźć. Nocne E2E, w którym ten test jedyny raz się wykonuje, chodzi po trwałym środowisku testowym, którego nikt nie zasila od nowa. Model nie mógł tego wiedzieć, bo mu tego nie wkleiłem, i nie ma sposobu, żeby to wywnioskował z logu. Naprawa jest nudna: kod rabatowy powstaje per test w fabryce danych, test sprząta po sobie, a zasilanie trwałego środowiska ma odtąd własny job. Dwadzieścia kolejnych nocnych przebiegów na zielono.

Bilans z całego notesu wygląda tak:

A tak rozkładały się kategorie, w które model strzelał:

Z tych dziewięciu potwierdzonych sześć nazwałbym sam w ciągu kwadransa, bo to są rzeczy, które w moim zestawie psują się od lat. Trzy były pomysłem, którego nie postawiłbym jako pierwszego, i to jest cała realna wartość tego ćwiczenia. Model nie skrócił mi odtwarzania ani o minutę, bo odtwarzanie to dwadzieścia przebiegów i czytanie trace’a. Poszerzył listę, którą wchodzę do odtwarzania, i zrobił to w dwadzieścia sekund.

Jeszcze jedna obserwacja, ważna dla każdego, kto chciałby czytać kolejność hipotez jako ranking. Wklejałem ten sam log dwa razy, w dwóch osobnych rozmowach, tym samym promptem; tej powtórki nie liczę w notesie. Za drugim razem hipotezy były trzy, sensowne, i w innej kolejności, a jedna z nich w pierwszej rozmowie nie wystąpiła. To nie jest wada, którą można wyprostować promptem. To jest właściwość narzędzia, o której trzeba pamiętać, kiedy ktoś pisze “model wskazał przyczynę”.

Gdzie model się myli

Sześć hipotez z moich szesnastu odrzuconych było nie tyle nietrafionych, ile niedotyczących mojego świata. Warto je nazwać, bo powtarzają się do znudzenia.

Zwala na Selenium przy Playwrightcie. Dwa razy dostałem wykład o implicitlyWait, ExpectedConditions i “znanej niestabilności sterownika przeglądarki”, przy logu, w którym stoi jak wół locator.click i waiting for element to be visible, enabled and stable. Playwright czeka na te trzy warunki sam i o tym jest cała ta sekcja logu. Model widzi “test przeglądarkowy, timeout” i sięga po najliczniejszy wzorzec w danych, na których się uczył, a tam Selenium ma dziesięć lat przewagi objętościowej.

Wymyśla joby, pliki i flagi. Dostałem polecenie “sprawdź krok Publish E2E w jobie e2e-nightly” oraz “ustaw retries w playwright.ci.config.ts”. Żadna z tych trzech nazw nie istnieje u mnie, a model napisał je bez cienia wątpliwości, jakby czytał moje repozytorium. To ta sama kategoria, którą złapałem w kwietniu na sugestiach Copilota przy recenzji kodu testów: kształt jest wiarygodny, konkret jest wymyślony. Raz dostałem też opcję expect.configure() z timeoutem per asercja, której w 1.36.1 po prostu nie ma.

Proponuje sleepa. Kiedy zapomniałem dopisać zdania o zakazie poprawek, dostałem w pakiecie page.waitForTimeout(3000) przed kliknięciem, podniesienie globalnego timeoutu do sześćdziesięciu sekund i --workers=1. Każda z tych trzech rzeczy sprawia, że czerwone znika, i żadna nie odpowiada na pytanie, dlaczego przycisk był wyłączony. Trzecia jest najgorsza, bo kosztuje wall-clock całego zestawu i wygląda jak decyzja inżynierska.

Czyta intencję w linii, która jest ostrzeżeniem. Raz dostałem całą hipotezę zbudowaną na linii z logu o nieużywanej zmiennej środowiskowej, która w moim pipelinie jest tam od roku i nic nie znaczy. Model nie ma jak odróżnić szumu, który zawsze jest w logu, od sygnału, który pojawił się dzisiaj. Ja to odróżniam, bo pamiętam, jak wygląda mój zielony przebieg.

Nie mówi “nie wiem”. To jest najbardziej męczące i nie zniknęło ani na gpt-3.5-turbo, ani na GPT-4. Poproszony o trzy hipotezy zawsze daje trzy, także wtedy, kiedy w logu jest jedna linia i sensowna odpowiedź to “wklej trace’a”. Przy jednym przebiegu z awarią sieci na agencie trzecia hipoteza była wypełniaczem i widziałem to od razu. Traktuję więc liczbę w prompcie jako limit, nie jako obietnicę, i nie czytam trzeciego punktu jako równoważnego pierwszemu.

Wniosek jest ten sam, który zapisałem w marcu i powtórzyłem w kwietniu, tylko na trzeciej warstwie. Model jest dobry w kształcie i słaby w konkretach zależnych od rzeczywistości, której nie widzi. Kategoria awarii, lista rzeczy do wykluczenia, przypomnienie o klasie problemu, na którą nie patrzyłem - tak. Nazwa joba, nazwa pliku konfiguracyjnego, istnienie opcji w mojej wersji runnera, historia mojego środowiska - nie, i te cztery sprawdzam co do jednej.

Czego to nie zmienia w warsztacie

Cała trudna część triage’u została tam, gdzie była, i chcę to zapisać wprost, żeby za rok nie wyszło, że w lipcu 2023 wymieniłem warsztat na czat.

Izolacja zostaje pierwszym krokiem, nie ostatnim. Kolejność, którą spisałem w równoległych testach na CI, jest tam nadal, wraz z całą nudną robotą: żaden statyczny stan, żaden sztywny port, żadna wspólna baza między plasterkami. Nie przepisuję tamtego wpisu i nie mam czego w nim zmienić, bo model nie zdejmuje ani jednego z tych wymagań. Ten flake, który tu opisałem, wziął się dokładnie z tego samego korzenia co wszystkie poprzednie: z danych, które są wspólne, chociaż nikt tego nie zadeklarował. To samo dotyczy miejsca, gdzie żyje stan między testami; reguła z porządkowania xUnit i NUnit brzmi tak samo jak w styczniu 2022: najpierw ustal, gdzie żyje stan, potem wybieraj atrybuty.

Ponawianie zostaje świadome. Polityki na Polly, które opisałem w lipcu 2021, są w moich testach integracyjnych i tam zostają, bo są od chwilowych usterek sieci i zewnętrznych usług. Nie owijam retry wokół testu, który przegrał o dane, i nie rozszerzam tamtego wpisu o “triage z modelem”, bo to dwie różne warstwy. Model, który proponuje retries jako lekarstwo na wyczerpany licznik użyć, dokładnie tę granicę zaciera, i to jest powód, żeby ją powtórzyć, nie żeby ją skasować.

Nie buduję dashboardu z AI. Nie podpinam modelu pod CI, żeby czytał czerwone przebiegi automatycznie, i mam do tego trzy powody, wszystkie prozaiczne. Pierwszy: dwa identyczne wywołania nie muszą dać tego samego wyniku, co pokazałem sobie dwiema rozmowami na tym samym logu, więc dostałbym w raporcie tekst, którego nie da się porównać z wczorajszym. Drugi: log z CI zawiera rzeczy, których nie wynosi się poza organizację, a automat nie redaguje sekretów, tylko wysyła to, co dostał. Trzeci: nikt by tego nie czytał. Automatyczny komentarz z trzema hipotezami pod każdym czerwonym przebiegiem to nowy szum, a ja od września 2022 mierzę u siebie odsetek przebiegów, w których coś padło bez zmiany w kodzie, właśnie po to, żeby szumu było mniej.

Nie ma też mowy o tym, żeby ktokolwiek inny niż człowiek zakładał albo zamykał zgłoszenie. Nocny przebieg u mnie ma właściciela z nazwiskiem w kalendarzu i to ustalenie z wrześniowej strategii nie zmienia się ani o przecinek. Rano ktoś patrzy i albo zakłada zgłoszenie, albo wyrzuca test. Model może być tym, z kim ten ktoś rozmawia przez pierwsze dwie minuty.

I rzecz, którą traktuję jako granicę, a nie jako etap przejściowy. gpt-4 jest w API od 6 lipca i mogę je zawołać ze skryptu, ale samo istnienie dostępu nie jest powodem, żeby wpisać model między czerwony wynik i moje zgłoszenie. Triage jest czynnością, w której decyduję, czyj to problem, i to jest dokładnie ta decyzja, której nie chcę oddać czemuś, co potrafi z pełnym przekonaniem podać nazwę nieistniejącego joba.

Podsumowanie

Po dziewięciu dniach notowania mam wniosek, który mieści się w jednym zdaniu: model jest u mnie szybszym brainstormem na pierwszym podziale awarii i niczym więcej.

Rozbijam to na trzy zdania, które chcę móc przeczytać za rok. Z 33 hipotez 9 potwierdziłem odtworzeniem, ale tylko 3 z nich były pomysłem, którego sam bym nie postawił, i to te trzy są całą zmianą. 16 hipotez odrzuciłem po odtworzeniu, w tym tę, którą model postawił jako najbardziej prawdopodobną w moim głównym przykładzie, więc kolejność na liście nie jest rankingiem. Ostatni krok, ten, który faktycznie wyjaśnił awarię, wyszedł z mojej wiedzy o różnicy między bramką a nocą, i model nie miał szansy go zrobić, bo tej wiedzy nie ma w logu.

Czego z tego nie wynika. Nie wynika, że mam narzędzie do utrzymywania testów, bo mam kartę w przeglądarce i wklejony log. Nie wynika, że czas triage’u u mnie spadł, bo nie spadł: dwadzieścia przebiegów i czytanie trace’a kosztują tyle samo co w czerwcu. Nie wynika, że przestałem czytać logi, bo bez przeczytania logu nie umiem nawet zredagować go do wklejenia.

Ownerem zgłoszenia zostaję ja i nie jest to kokieteria. Pod ticketem, który idzie do zespołu ze zdaniem “to jest błąd produktu, nie flake”, podpisuję się nazwiskiem, a podpisać się można tylko pod czymś, co się odtworzyło. Model skrócił mi drogę do listy podejrzanych i nie skrócił ani o minutę drogi od listy do dowodu. To drugie zawsze było droższe i w lipcu 2023 nadal jest.

Za miesiąc albo dwa będę wiedział, czy te trzy nieoczywiste hipotezy z lipca to trwały zysk, czy przypadek dziewięciu dni. Do tego czasu wracam z tym do pytania, które zadaję sobie przy każdym nowym narzędziu: gdzie to się mieści w całym procesie testowym. Szybsza lista hipotez nie naprawia procesu, w którym nikt nie patrzy na ranny raport. Sprawia tylko, że ten, kto patrzy, ma o czym pomyśleć zanim kliknie “re-run”.