Debugging Techniques - rozwiązywanie problemów

Serwis zwraca zły wynik i nie wiadomo dlaczego. Wstawiasz

console.log

przed podejrzaną linią, restartujesz, patrzysz. Za mało - dokładasz drugi. I trzeci. Po kwadransie masz kilkanaście wydruków, konsolę pełną śmieci i wciąż nie wiesz, w którym miejscu wartość się psuje. Potem połowa tych wydruków zostaje w kodzie na zawsze.

Zwiadowca legionu nie działa po omacku. Ma drabinę narzędzi: najpierw patrzy z obozu, potem wysyła patrol, a gdy trzeba - zatrzymuje marsz i bada teren krok po kroku. Ta lekcja ustawia taką drabinę dla Twojego kodu.

Drabina narzędzi

Cztery szczeble, od wbudowanych po zewnętrzne:

1. NestJS Logger - wbudowany, zawsze pod ręką. Pokazuje, co się stało, ale nie zatrzymuje programu.
2. Node.js Inspector - uruchamiany flagą

   --inspect

   , pozwala zatrzymać program i obejrzeć jego wnętrze.
3. VS Code Debugger - ten sam mechanizm, tylko z breakpointami klikanymi w edytorze zamiast w przeglądarce.
4. Zewnętrzne APM - New Relic, Datadog i podobne. Obserwują aplikację na produkcji, gdzie żadnego breakpointa nie postawisz.

Kolejność nie jest przypadkowa: każdy kolejny szczebel kosztuje więcej przygotowania, więc wchodzisz na niego dopiero, gdy poprzedni nie wystarczył.

Szczebel pierwszy: poziomy logowania

NestJS ma wbudowany logger z pięcioma poziomami:

error

,

warn

,

log

,

verbose

,

debug

. W trybie deweloperskim dostępne są wszystkie - właśnie po to, żeby móc zejść głębiej bez dokładania kodu.

Poziomy wybierasz przy tworzeniu aplikacji:

1// main.ts
2async function bootstrap() {
3  const app = await NestFactory.create(AppModule, {
4    logger: ['error', 'warn', 'log', 'verbose', 'debug'],
5  });
6
7  await app.listen(3000);
8}

Tablica w opcji

logger

mówi, które poziomy mają być widoczne. Podanie samego

['error', 'warn']

wycisza resztę - i to jest zwykle ustawienie produkcyjne, bo

debug

na produkcji zalałby dyski. W development podajesz pełen zestaw.

Zwróć uwagę, że konfiguracja idzie jako drugi argument

NestFactory.create

, przy tworzeniu aplikacji. Nie ma metody w rodzaju

app.setLogLevel()

ani

Logger.setLevel()

- poziomy ustala się raz, na starcie.

Logger zamiast console.log

Mając poziomy, zastępujemy wydruki prawdziwym loggerem:

1@Injectable()
2export class LegionsService {
3  private readonly logger = new Logger(LegionsService.name);
4
5  async findOne(id: number) {
6    this.logger.debug(`Szukam legionu ${id}`);
7
8    const legion = await this.repo.findOne({ where: { id } });
9
10    if (!legion) {
11      this.logger.warn(`Legion ${id} nie istnieje`);
12      throw new NotFoundException();
13    }
14
15    return legion;
16  }
17}

new Logger(LegionsService.name)

nadaje loggerowi kontekst - nazwę klasy, która pojawi się w każdym wpisie. Dzięki temu w konsoli widzisz, skąd pochodzi komunikat, bez dopisywania tego ręcznie do treści.

Przewaga nad

console.log

jest praktyczna: wpisy

debug

znikają same, gdy zmienisz konfigurację na produkcyjną. Nie musisz ich usuwać przed wdrożeniem ani pamiętać, gdzie je zostawiłeś - dlatego to polecam jako nawyk, @name: nie wydruki, tylko logger z właściwym poziomem.

Szczebel drugi: Node.js Inspector

Logger pokazuje, co program zrobił. Czasem potrzebujesz zobaczyć, co robi w tej chwili - wtedy zatrzymujesz go w wybranym miejscu.

Służy do tego flaga

--inspect

, która włącza protokół debugowania V8 i pozwala podłączyć się do działającego procesu:

1node --inspect dist/main.js

Droga jest czterostopniowa. Uruchom aplikację z flagą

--inspect

. Otwórz Chrome DevTools pod adresem

chrome://inspect

i podłącz się do procesu. Ustaw breakpoint w kodzie - miejsce, w którym program ma się zatrzymać. Analizuj zmienne i call stack, czyli stos wywołań mówiący, którędy program tu dotarł.

Ten czwarty krok jest tym, czego

console.log

nie da: widzisz wszystkie zmienne w zasięgu, a nie tylko te, które wcześniej zgadłeś i wydrukowałeś. Możesz też przejść program krok po kroku i zobaczyć, w którym miejscu wartość zmienia się na złą.

Sama flaga niczego nie sprawdza ani nie uruchamia - jedynie otwiera drzwi, przez które debugger może zajrzeć do środka.

Szczeble wyżej

VS Code Debugger korzysta z tego samego protokołu, tylko breakpointy stawiasz klikając obok numeru linii, a zmienne oglądasz w panelu edytora. Nic nowego pod spodem - wygodniejsza obsługa tego samego mechanizmu.

Zewnętrzne APM rozwiązują inny problem: na produkcji nie zatrzymasz aplikacji breakpointem, bo obsługuje prawdziwy ruch. Narzędzia w rodzaju New Relic czy Datadog zbierają dane w tle - czasy odpowiedzi, wyjątki, wolne zapytania - i pozwalają dojść do przyczyny po fakcie, na podstawie tego, co zebrały.

Podsumowanie

Zwiad prowadzony po kolei, nie po omacku:

• drabina narzędzi od wbudowanych do zewnętrznych: NestJS Logger → Node.js Inspector → VS Code Debugger → zewnętrzne APM,
• logger ma pięć poziomów:

  error

  ,

  warn

  ,

  log

  ,

  verbose

  ,

  debug

  - w trybie development dostępne są wszystkie,
• poziomy ustawiasz jako drugi argument

  NestFactory.create(AppModule, { logger: [...] })

  - nie ma

  setLogLevel

  ani

  Logger.setLevel

  ,
• na produkcji zwykle

  ['error', 'warn']

  , w development pełen zestaw,

• new Logger(NazwaKlasy.name)

  nadaje wpisom kontekst, a wpisy

  debug

  same znikają po zmianie konfiguracji,
• flaga

  --inspect

  włącza protokół debugowania V8 i pozwala podłączyć debugger; niczego nie sprawdza ani nie uruchamia,
• cztery kroki: uruchom z

  --inspect

  , otwórz

  chrome://inspect

  , ustaw breakpoint, analizuj zmienne i call stack,
• przewaga nad wydrukami: widzisz wszystkie zmienne w zasięgu, nie tylko te zgadnięte wcześniej,
• VS Code Debugger to ten sam protokół z wygodniejszą obsługą,
• na produkcji breakpointa nie postawisz - tam pracują APM zbierające dane w tle.

W następnej lekcji zajmiemy się tym, co dzieje się przy zatrzymywaniu aplikacji - graceful shutdown, czyli zwijanie obozu bez porzucania rannych. A na razie zapamiętaj: logger mówi, co się stało; inspector pozwala zatrzymać marsz i zobaczyć, co dzieje się teraz.