Programujesz sobie spokojnie, aż tu nagle wyskakuje Okno Śmierci.

Pewnie przejrzysz ostatnie zmiany w kodzie i znajdziesz coś podejrzanego. Ale jeśli wciąż nie wiesz co mogło nasz problem spowodować, pozostanie nam stare, dobre, klasyczne debugowanie.

Przedebugujmy się, zatem, aż do źródła naszego problemu.

Zwróćmy uwagę - gdzie się zatrzymaliśmy:

Ma to sens bo, Ozone automatycznie ustawił breakpointy na faultach (Vector Catch).

W Call Stack, jeśli mamy szczęście, zobaczymy która funkcja była wywoływana wcześniej.

Double click na niej i jesteśmy chyba w miejscu gdzie powstał błąd.

Czyli wywalamy się tu:

Adres instrukcji to 0x205AE. To zostało nam zgłoszone przez Okno Śmierci na samym początku:

Przydaje się, kiedy np. z jakiegoś powodu nie mamy pełnej informacji  w Call Stacku.

W Dissasembly od razu widać, że ładujemy tu do rejestru R0 wartość spod adresu (R3+R0<<2), która pewnie jest nieodpowiednia. Niewiele to mówi, ale ponieważ wartość rejestrów raczej się nie zmieniła jeszcze, to możemy sprawdzić wartości w kontekście języka C. Local Data mówi, że nasz log_type to zdecydowanie podejrzana wartość.
Tym bardziej, że Quick Watch na tabeli pokazuje rozmiar 4:

No to pytanie skąd mamy tą dziwną wartość w 'log_type'?

Przez Call Stack wskakujemy w funkcję “wyżej”/wcześniej. I co tu widzimy:

Ano, po pierwsze analizując kod:
nasz problematyczny parametr jest brany z data wywodzącego się z ctx który pochodzi z backend->cb.
No niestety sam backend jest już out of scope. 

No to teraz mamy dwie możliwości (poza użyciem Trace):

1. Można tak sobie jeszcze poskakać w górę aby dowiedzieć się skąd ten backend pochodzi i kto go tu przekazuje analizując kod;
2. Można w tym miejscu ustawić breakpointa i puścić wszystko od nowa. Najlepiej włączyć breakpoint tuż przed wystąpieniem błędu jeśli funkcja jest używana często (ja wiedziałem że komenda shella powoduje błąd). Skryptowo można chyba też włączyć breakpoint kiedy jakiś inny się ztriggeruje. Można też użyć warunków breakpointa. Zatrzymajmy się tylko jeśli ctx == 0x0000 0000 (bo to podejrzana wartość);

Stawiamy breakpoint, prawy klik i Edit Breakpoint:

Wywołujemy przyczynę błędu i czekamy.

Teraz faktycznie widać, że przekazujemy jakiś abstrakcyjnie duży data->log_format_current.
Pewnie dlatego, że nasz ctx w tym momencie to “0”. Czyżby ktoś/coś nadpisał nam backend->cd->ctx?

Teraz wystarczy ustawić data breakpoint na każdy zapis pod adres 0x2000 0B9C i znowu puścić wszystko od nowa.

Klikamy prawym na tym ctx i Set Data Breakpoint:

Dla zmiennych globalnych pewnie by wystarczyło, ale Ozone czasem się tu gubi, więc przełączamy na manual - adres mogliśmy wpisać ręcznie, ale w ten sprytny sposób zrobi za nas to Ozone:

No to: reset i od nowa.
I pierwsze zatrzymanie:

Można się było spodziewać, że struktura jest kiedyś inicjowana, więc jak na razie jest wszystko ok.
Kontynuujemy debug.
Jeśli częściej do naszego cb->ctx są wpisywane, nazwijmy to, poprawne wartości, i co chwila się zatrzymujemy z powodu wpisywania “poprawnej” wartości wystarczy przeedytować nasz data breakpoint, tak by łapał się tylko kiedy wpisywane jest “0”:

Po wywołaniu przyczyny błędu zatrzymamy się tuż po tym jak “0” nadpisuje poprzednią poprawną wartość cb->ctx:

Przeszukując Call Stack wstecz szybko dojdziemy do miejsca, gdzie context jest radośnie bezpośrednio podawany jako NULL. 

Voila!
Przyczyna crasha znaleziona… Czas poszukać winnego ;) 

I można by to zakończyć, ale ta sama historia w przypadku użycia VSC  “nRF Connect” już nie jest taka prosta.
Debugując w VSC nasz program zatrzyma się w zupełnie innym miejscu:

Long story short: to jest wtórny błąd, spowodowany obsługą naszego źródłowego buga.

Przyczyny naszego crasha nie znajdziemy już w CALL STACK, ani nawet analizując baktrace (-exec bt w DEBUG CONSOLE).
Powód jest taki, że domyślnie środowisko Zephyra ustawia breakpointy w części kodu już po Zephyrowej obsłudze błędu.
W większości przypadków to świetnie działa, ale tu błąd jest w mechanizmie logowania, który jest używany do obsługi pierwotnego błędu, więc próbując wyświetlić w logu opis błędu powodujemy następny.

Włączmy więc mechanizm wczesnego ostrzegania, który był tak użyteczny w przypadku Ozone.

Dodajemy breakpoint na wywołaniu funkcji z_arm_fault w sekcji BREAKPOINTS:

Można też poprzez DEBUG CONSOLE: -exec break z_arm_fault

I po ponownym uruchomieniu zatrzymamy się tuż po pierwszym, źródłowym problemie. 

Stąd, poprzez CALL STACK, już dotrzemy do pierwszego objawu: duża wartość log_type w funkcji log_format_func_t_get().

Dalej to już znacie historię.
‍
Ale, szczerze, to wygodniej się pułapki w Ozone ustawia.

‍