Kurs Nordic nRF z BT (2). Debug i LOG

Kurs Nordic nRF z BT (2). Debug i LOG

W poprzedniej części naszego kursu pokazaliśmy, jak w kilku krokach rozpocząć pracę w środowisku opartym na nRF Connect SDK. Uruchomiliśmy program Hello World w wersji embedded (na płytce nRF5340 DK), a także pokazaliśmy, jak można skonfigurować własną płytkę PCB z układem nRF5340. Tym razem skupimy się na metodach śledzenia procesu wykonywania kodu, które wspierane są przez zainstalowane przez nas narzędzia. Poza standardowym printowaniem i klasycznym debugiem opiszemy wybrane funkcje obszernego modułu logowania dostarczanego wraz z Zephyrem.

Prawdziwe „Hello, World!”

Aktualnie nasz program początkowy komunikuje się z użytkownikiem jedynie przez miganie diodą. Pora to zmienić, wprowadzając do pliku main.c funkcję printk, która w prosty sposób pozwoli nam wysyłać wiadomości przez port szeregowy UART. Oczywiście edytując naszą aplikację hello_world, wciąż korzystamy z przygotowanego wcześniej środowiska, w tym rozszerzenia nRF Connect w VS Code. Zmodyfikowany kod, widoczny na listingu 1, wysyła początkową wiadomość tuż po wejściu do funkcji main oraz cyklicznie wewnątrz pętli.

#include <zephyr/kernel.h>
#include <zephyr/drivers/gpio.h>

static const struct gpio_dt_spec led = GPIO_DT_SPEC_GET(DT_NODELABEL(led0), gpios);

int main(void) {
printk("Hello, World!\n");

if (!gpio_is_ready_dt(&led))
return 0;

gpio_pin_configure_dt(&led, GPIO_OUTPUT_ACTIVE);

int counter = 0;

while (1) {
printk("Hello, World %d!\n", counter);
++counter;
gpio_pin_toggle_dt(&led);
k_msleep(1000);
}
return 0;
}
 
Listing 1. Plik main.c z dodanymi funkcjami printk

Jeżeli również korzystasz z płytki nRF5340 DK, podłączonej do komputera przewodem USB, w tym momencie projekt wystarczy ponownie przebudować i wgrać plik wynikowy z użyciem wbudowanego J-Linka. Domyślna konfiguracja UART w devicetree (nrf5340dk_nrf5340_cpuapp.dts) zawiera wszystko, co potrzebne do przesyłania wiadomości. Ponadto sam hardware jest tak przygotowany, że linie sygnałowe komunikacji szeregowej, wychodzące z SoC-a, są podłączone do debuggera i udostępnione jako wirtualne porty COM. Oznacza to, że jedyne, co musimy zrobić, to w sekcji CONNECTED DEVICES rozwinąć pole z widocznym numerem seryjnym i kliknąć na ikonę wtyczki po prawej stronie pola VCOM1 (rysunek 1).

Rysunek 1. Pole VCOM1 w sekcji CONNECTED DEVICES

Spowoduje to otwarcie okna wyboru portu szeregowego, w którym klikamy na jedyny dostępny element na liście (rysunek 2).

Rysunek 2. Okno wyboru portu szeregowego

U dołu okna VS Code, w zakładce TERMINAL, powinniśmy teraz zobaczyć konsolę z wiadomościami odbieranymi od procesora (rysunek 3).

Rysunek 3. Wiadomości (printk) odbierane w konsoli VCOM1

Warto zaznaczyć, że do komunikacji szeregowej możemy również użyć wielu innych, popularnych programów, takich jak Putty (Windows) czy GTKTerm (Linux).

Zwróciłeś też być może uwagę na port VCOM0, który obecnie nie odbiera żadnych wiadomości. Jak już wspominaliśmy na początku kursu, SoC nRF5340 ma dwa osobne procesory – application oraz network. Domyślna konfiguracja sprzętowa naszej płytki przewiduje możliwość przesyłania przez każdy z nich wiadomości na osobnych peryferiach UART, stąd też dwa niezależne wirtualne porty widoczne w interfejsie. Jest to rozwiązanie bardzo praktyczne i nie wymaga od nas stosowania żadnych przejściówek. A co, jeśli jednak chcielibyśmy podłączyć się bezpośrednio do pinów TX i RX wychodzących z układu? W tym celu wystarczy przestawić dostępne na płytce przełączniki FLOW CONTROL na pozycję OFF (rysunek 4).

Rysunek 4. Przełączniki linii sygnałowych UART

Próba skompilowania i uruchomienia kodu z funkcjami printk na własną płytkę z układem nRF5340 może zakończyć się niepowodzeniem. W takim przypadku należy upewnić się, że UART wraz z konsolą jest prawidłowo skonfigurowany w devicetree (listing 2) oraz odpowiednie ustawienia KConfig są włączone dla projektu (listing 3).

/ {
chosen {
zephyr,console = &uart0;
};
};

&pinctrl {
uart0_default: uart0_default {
group1 {
psels = <NRF_PSEL(UART_TX, 0, 20)>,
<NRF_PSEL(UART_RTS, 0, 19)>;
};
group2 {
psels = <NRF_PSEL(UART_RX, 0, 22)>,
<NRF_PSEL(UART_CTS, 0, 21)>;
bias-pull-up;
};
};

uart0_sleep: uart0_sleep {
group1 {
psels = <NRF_PSEL(UART_TX, 0, 20)>,
<NRF_PSEL(UART_RX, 0, 22)>,
<NRF_PSEL(UART_RTS, 0, 19)>,
<NRF_PSEL(UART_CTS, 0, 21)>;
low-power-enable;
};
};
};

&uart0 {
status = "okay";
current-speed = <115200>;
pinctrl-0 = <&uart0_default>;
pinctrl-1 = <&uart0_sleep>;
pinctrl-names = "default", "sleep";
};
 
Listing 2. Przykładowa konfiguracja konsoli UART w devicetree
CONFIG_SERIAL=y
CONFIG_CONSOLE=y
CONFIG_UART_CONSOLE=y

Listing 3. Ustawienia KConfig niezbędne do uruchomienia przykładu

Debug

Zanim bardziej rozbudujemy nasz program, zaprezentujmy, w jaki sposób rozszerzenie nRF Connect wspiera proces debugu. Zacznijmy od ustawienia pierwszego breakpointa w pliku main.c, na wywołaniu funkcji printk w pętli while. VS Code pozwala to zrobić w podglądzie pliku, poprzez kliknięcie po lewej stronie numeru linii (rysunek 5).

Rysunek 5. Breakpoint ustawiony w linii 17 pliku main.c

Czerwona kropka oznacza, że punkt został ustawiony i możemy uruchomić debug. W tym celu klikamy w sekcji ACTIONS na pole Debug (rysunek 6).

Rysunek 6. Pole Debug w sekcji ACTIONS

Zostaniemy przeniesieni do zakładki Run and Debug, widocznej po lewej stronie edytora na pasku aktywności (activity bar). Zobaczymy również nowy panel z różnymi opcjami debugu (rysunek 7).

Rysunek 7. Panel debug

Klikamy na pierwszy przycisk z lewej strony (Continue) i niemal od razu powinniśmy zatrzymać się w oznaczonym przez nas punkcie. Od teraz każde ponowne kliknięcie powinno skutkować jednorazowym wykonaniem pętli i zatrzymaniem w tym samym miejscu. Możemy jednocześnie śledzić zawartość konsoli VCOM1 i aktualny stan diody, a także monitorować zawartość naszej zmiennej lokalnej counter w sekcji VARIABLES (rysunek 8).

Rysunek 8. Podgląd zmiennych w sekcji VARIABLES

Pozostałe opcje procesu debugowania powinny wyglądać dość znajomo, dlatego poprzestaniemy na zaprezentowanym dotychczas opisie. Warto jednak wspomnieć, że rozszerzenie nRF Connect wspiera również popularny program do debugowania o nazwie Ozone (rysunek 9).

Rysunek 9. Okno programu Ozone

Jeżeli narzędzie mamy zainstalowane w systemie, to pod standardową opcją Debug, w sekcji ACTIONS, zobaczymy również pole Debug with Ozone (rysunek 10), które po kliknięciu nie tylko otwiera sam program, ale również przekazuje niezbędną konfigurację.

Rysunek 10. Fragment sekcji ACTIONS po wykryciu oprogramowania Ozone

Na tym etapie teoretycznie mamy wszystko, co niezbędne do śledzenia wykonywania programów. W pakiecie z Zephyrem mamy jednak moduł, który może jeszcze bardziej ułatwić nam pracę.

LOG

Funkcja printk często wystarcza, by uzyskać kluczowe informacje, w konkretnym miejscu, podczas wykonywania naszego programu. Jednak bardzo szybko możemy znaleźć się w sytuacji, kiedy część wiadomości zawiera ważne dane o błędach, a inne są istotne jedynie na etapie debugowania. Na szczęście Zephyr ma dość rozbudowany moduł logowania, który bez przeszkód włączymy z poziomu ustawień Kconfig, dodając jedną linię do naszego projektowego pliku prj.conf. Jednak tym razem, zamiast edytować plik ręcznie, wykorzystamy tę okazję do pokazania, jak to zrobić z użyciem interfejsu graficznego. W sekcji ACTIONS klikamy na pole nRF Kconfig GUI (rysunek 11).

Rysunek 11. Pole nRF Kconfig GUI w sekcji ACTIONS

W nowo otwartym oknie nRF Kconfig możemy wpisać w polu wyszukiwania „log” lub kolejno rozwijać następujące elementy ścieżki: Zephyr Kernel Configuration > Subsystems and OS Services > Logging. Znajdziemy tam jeszcze jedną sekcję Logging z kwadratowym polem, które należy zaznaczyć (rysunek 12). Następnie zapisujemy zmiany, klikając na przycisk Save to file.

Rysunek 12. Okno Kconfig GUI z wybraną opcją Logging

W tym momencie otworzy się nasz plik z ustawieniami, do którego dodana została nowa opcja CONFIG_LOG=y. Warto zaznaczyć, że dzięki GUI można w dość łatwy sposób eksplorować kolejne odnogi konfiguracji tego modułu oraz wielu innych.

Mimo że dodaliśmy tylko jedną opcję, to spowodowała ona wprowadzenie szeregu innych ustawień Kconfiga, powiązanych z modułem logowania. Możemy je podejrzeć, zaglądając do pliku wyjściowego build/zephyr/.config. Znajdziemy tam między innymi ustawienia widoczne na listingu 4.

# Logging
#
CONFIG_LOG=y
CONFIG_LOG_CORE_INIT_PRIORITY=0
CONFIG_LOG_MODE_DEFERRED=y
# CONFIG_LOG_MODE_IMMEDIATE is not set
# CONFIG_LOG_MODE_MINIMAL is not set
# CONFIG_LOG_FRONTEND is not set
# CONFIG_LOG_FRONTEND_OPT_API is not set
# CONFIG_LOG_CUSTOM_HEADER is not set
# CONFIG_LOG_MULTIDOMAIN is not set

#
# Logging levels filtering
#
# CONFIG_LOG_RUNTIME_FILTERING is not set
CONFIG_LOG_DEFAULT_LEVEL=3
CONFIG_LOG_OVERRIDE_LEVEL=0
CONFIG_LOG_MAX_LEVEL=4
# end of Logging levels filtering

#
# Processing
#
CONFIG_LOG_PRINTK=y
CONFIG_LOG_MODE_OVERFLOW=y
# CONFIG_LOG_BLOCK_IN_THREAD is not set

Listing 4. Fragment pliku .config z różnymi opcjami logowania

Być może zastanawiasz się, skąd system konfiguracji Kconfig wiedział, co powinien dodać? W skrócie rzecz ujmując, mechanizm ten opiera się na sprawdzaniu zależności pomiędzy różnymi ustawieniami w plikach definiujących każdą opcję. Mamy w nich możliwość definiowania różnych bloków warunkowych, a nawet wykonywania prostych obliczeń.

Co ciekawe, finalne wartości ustawień widoczne są również jako makra w kodzie C dzięki automatycznie generowanemu plikowi build/zephyr/include/generated/autoconf.h (listing 5).

#define CONFIG_ASSERT_VERBOSE 1
#define CONFIG_LOG 1
#define CONFIG_LOG_CORE_INIT_PRIORITY 0
#define CONFIG_LOG_MODE_DEFERRED 1
#define CONFIG_LOG_DEFAULT_LEVEL 3
#define CONFIG_LOG_OVERRIDE_LEVEL 0
#define CONFIG_LOG_MAX_LEVEL 4
#define CONFIG_LOG_PRINTK 1
#define CONFIG_LOG_MODE_OVERFLOW 1

Listing 5. Fragment pliku autoconf.h

Wśród naszych nowych ustawień projektu znajdziemy CONFIG_LOG_PRINTK=y, co oznacza, że od tej chwili funkcje printk będą przekierowane do modułu logowania. Jeżeli ponownie zbudujemy aplikację i wgramy ją na płytkę, to w konsoli VCOM1 wciąż będziemy otrzymywać te same wiadomości co wcześniej, ale z dość istotną różnicą. Nie będą one przychodziły od razu po wykonaniu instrukcji, co z pewnością zauważysz podczas debugowania. Okazuje się, że opcja CONFIG_LOG_MODE_DEFERRED=y spowodowała dodanie do naszego projektu nowego wątku (thread/task), który od teraz odpowiedzialny jest za wysyłanie logów w swoich własnych slotach czasowych. Jedną z zalet takiego rozwiązania jest skrócenie czasu spędzonego w miejscu wywołania funkcji logujących. Funkcjonalność tę można najbardziej docenić podczas wysyłania wiadomości z wnętrza procedur obsługi przerwań (byle nie za długich i nie za często).

Mimo że funkcje printk wciąż działają, to jednak nie pozwolą nam one skorzystać z wielu zalet Zephyrowego modułu logowania. Do tego potrzebujemy dedykowanych makr LOG. Zacznijmy od wprowadzenia zmian w pliku main.c (listing 6).

#include <zephyr/kernel.h>
#include <zephyr/drivers/gpio.h>
#include <zephyr/logging/log.h>

LOG_MODULE_REGISTER(main_module, LOG_LEVEL_DBG);

static const struct gpio_dt_spec led = GPIO_DT_SPEC_GET(DT_NODELABEL(led0), gpios);

int main(void) {
LOG_INF("Hello, World!");

if (!gpio_is_ready_dt(&led))
return 0;

gpio_pin_configure_dt(&led, GPIO_OUTPUT_ACTIVE);

int counter = 0;

while (1) {
switch (counter % 4) {
case 0: LOG_DBG("Hello, World %d!", counter); break;
case 1: LOG_INF("Hello, World %d!", counter); break;
case 2: LOG_WRN("Hello, World %d!", counter); break;
case 3: LOG_ERR("Hello, World %d!", counter); break;
}
++counter;
gpio_pin_toggle_dt(&led);
k_msleep(1000);
}
return 0;
}
 
Listing 6. Plik main.c po wprowadzeniu makr LOG

Tym razem wysyłanie wiadomości mamy w całości zrealizowane makrami LOG_DBG, LOG_INF, LOG_WRN i LOG_ERR. Po zbudowaniu i wgraniu tak zmodyfikowanego programu w konsoli VCOM1 zobaczymy logi w nowym formacie (rysunek 13).

Rysunek 13. Logi wysłane makrami LOG

Każdy z czterech rodzajów wiadomości wyróżnia się własnym poziomem logowania określającym jego „ważność”. Dzięki temu możemy filtrować nasze logi w zależności od potrzeb. Przykładowo, jeżeli w linii z makrem LOG_MODULE_REGISTER zmienimy LOG_LEVEL_DBG na LOG_LEVEL_ERR, to urządzenie wyśle jedynie informacje oznaczone jako błędy (rysunek 14), gdyż na etapie kompilacji „wycięte” zostaną wszystkie wywołania LOG poza LOG_ERR.

Rysunek 14. Logi po wybraniu poziomu LOG_LEVEL_ERR w przypadku modułu main

Przy odpowiedniej konfiguracji projektu poziom filtracji logów (w przypadku wybranych modułów) można również zmieniać w czasie wykonywania programu, co może być przydatne w bardziej rozbudowanych aplikacjach.

Warto jeszcze dodać, że większość bibliotek Zephyra jest uzbrojona w logi. Uruchamiając nowy moduł, warto sprawdzić, czy nie ma on gotowych opcji, które wystarczy włączyć. Przykładowo: dołączając do kodu obsługę I²S, możemy odblokować wszystkie poziomy logów, dopisując do prj.conf linię CONFIG_I2S_LOG_LEVEL_DBG=y.

RTT

Dotychczas wysyłaliśmy wiadomości jedynie przez UART, ale nietrudno wyobrazić sobie sytuację, w której nie mamy wolnego portu szeregowego. Na szczęście moduł logowania przewiduje możliwość przekierowania logów do innych backendów. Jednym z nich może być RTT (Real-Time Transfer). Jest to technologia komunikacji opracowana przez SEGGER, a używana głównie w połączeniu z debuggerem J-Link. Mówiąc w dużym uproszczeniu, możemy stwierdzić, że jest to mechanizm pozwalający na zapisywanie komunikacji do bufora w pamięci RAM, który następnie jest odczytywany przez oprogramowanie debuggera.

Obsługę RTT włączamy również w pliku prj.conf, dodając opcje pokazane na listingu 7.

CONFIG_USE_SEGGER_RTT=y
CONFIG_LOG_BACKEND_RTT=y
CONFIG_LOG_BACKEND_RTT_MODE_OVERWRITE=y

Listing 7. Konfiguracja RTT wraz z backendem

Pierwsza z nich dołączy podstawowe oprogramowanie RTT do naszego projektu, druga włączy wysyłanie loga poprzez RTT, a trzecia spowoduje, że nieodebrane przez nasz komputer logi będą po jakimś czasie nadpisywane nowymi.

Wtyczka nRF Connect dostarcza nam narzędzie do czytania z nowo skonfigurowanego backendu, które uruchamiamy analogicznie do VCOM1, przy czym tym razem klikamy na wtyczkę przy polu RTT (por. rysunek 1). W wyświetlonym oknie wybieramy nRF5340_xxAA_APP (rysunek 15).

Rysunek 15. Włączanie konsoli RTT – wybór rdzenia

Następnie klikamy jedyną dostępną opcję, która automatycznie wyszuka adres pamięci przeznaczonej na bufor RTT (rysunek 16).

Rysunek 16. Włączanie konsoli RTT – wybór konfiguracji

Od teraz nasz program będzie wysyłał wiadomości zarówno przez konsolę VCOM1, jak i RTT.

Warto dodać, że bardzo wygodną opcją jest korzystanie z terminalu RTT bezpośrednio we wspomnianym wcześniej programie Ozone.

Zephyr przewiduje wiele innych backendów, takich jak file system czy bluetooth. Więcej informacji dotyczących logowania możemy znaleźć w oficjalnej dokumentacji [1].

Podsumowanie

W artykule przedstawiliśmy, jak nRF Connect wraz z systemem Zephyr wspierają programistę w pisaniu aplikacji i śledzeniu wykonywanych przez procesor instrukcji. Opisaliśmy przy tym wybrane funkcjonalności modułu logowania, który od teraz na stałe znajdzie miejsce w naszym arsenale programistycznym. Przedstawiona powyżej konfiguracja projektu to doskonała podstawa przyszłych prac nad bardziej zaawansowanymi aplikacjami embedded.

Krzysztof Kierys
Paweł Jachimowski

Odnośniki w tekście
1. https://docs.zephyrproject.org/latest/services/logging/index.html

Artykuł ukazał się w
Elektronika Praktyczna
lipiec 2024

Elektronika Praktyczna Plus lipiec - grudzień 2012

Elektronika Praktyczna Plus

Monograficzne wydania specjalne

Elektronik październik 2024

Elektronik

Magazyn elektroniki profesjonalnej

Raspberry Pi 2015

Raspberry Pi

Wykorzystaj wszystkie możliwości wyjątkowego minikomputera

Świat Radio wrzesień - październik 2024

Świat Radio

Magazyn krótkofalowców i amatorów CB

Automatyka, Podzespoły, Aplikacje wrzesień 2024

Automatyka, Podzespoły, Aplikacje

Technika i rynek systemów automatyki

Elektronika Praktyczna październik 2024

Elektronika Praktyczna

Międzynarodowy magazyn elektroników konstruktorów

Elektronika dla Wszystkich październik 2024

Elektronika dla Wszystkich

Interesująca elektronika dla pasjonatów