Getting Started With Zephyr: Using GDB To Fix a Driver Bug

• RTOS
• Sensors
• C Programming

Introduction

Last year, Jacob and I hosted a webinar demonstrating how to add custom hardware to an embedded software application based on The Zephyr Project. If you're interested and want to follow along, you can sign up for the webinar (https://us8.list-manage.com/survey?u=ec02eb9313642...) and we'll send you a copy of the recording. 

In the webinar, we showed how to add support for the Adafruit TSL2591 light sensor (https://www.adafruit.com/product/1980) on the STM32L4 Discovery kit IoT node (https://estore.st.com/en/b-l475e-iot01a1-cpn.html). Unfortunately, while we were successful in adding support for the TSL2591 sensor, the driver failed to initialize. 

Of course, I wanted to investigate why the driver failed to initialize in the webinar. In this blog post, I demonstrate how:

• To reproduce the issue shown in the webinar.
• I used GDB to investigate the failure.
• I discovered the defect in the driver.
• I hypothesized and verified a possible fix.

Bonus: I also upstreamed the solution, and it got accepted! You can view the PR here (https://github.com/zephyrproject-rtos/zephyr/pull/...) if you'd like to understand the process to contribute to the Zephyr Project.

Note: I am most comfortable using the Linux terminal regularly, and this is reflected in the remainder of the blog post. The steps may differ if you use a GUI (such as VS Code) or another operating system.

Reproducing The Error

Let's review the steps needed to reproduce the issue shown in the webinar. First, we can follow the steps outlined below to create our working directory, create a Python virtual environment, and install the necessary tools:

$> mkdir -p embeddedrelated/tsl2591-fix
$> cd embeddedrelated/tsl2591-fix
$> python3 -m venv .env
$> source .env/bin/activate
$> pip3 install west
$> pip3 install pyelftools

Second, we can retrieve the application, including the Zephyr release with the defect, by following the steps outlined below:

$> mkdir -p embeddedrelated/tsl2591-fix
$> west init -m https://github.com/mabembedded/zephyr-tsl2591.git 
$> west update

Finally, we can follow these steps to build the application and flash it to STM32L4 Discovery IoT node:

$> west build -p -b bl475_iot1 zephyr-tsl2591.git/app/
$> west flash

If we power the STM32L4 Discovery IoT node and connect to it via a terminal, we can see the following output from the webinar:

[00:00:00.000,000] <err> TSL2591: Failed to reset device
[00:00:00.000,000] <err> TSL2591: Failed to setup device
*** Booting Zephyr OS build v3.7.0 ***
sensor: device not ready.
uart:~$

We can arrive at the following conclusions based on the error above:

• The driver is failing to set up the TSL2591.
• Specifically, the driver is failing to reset the TSL2591, most likely while it's performing the initial setup.

We can confirm these conclusions by reviewing the driver source code before the fix (found here: https://github.com/zephyrproject-rtos/zephyr/blob/...). We can see that in the tsl2591_init function calls tsl2591_setup: 

static int tsl2591_init(const struct device *dev)
{
.
.
    ret = tsl2591_setup(dev);
        if (ret < 0) {
        LOG_ERR("Failed to setup device");
        return ret;
    }
.
.
}

Additionally, we can see that the driver first attempts to reset the TSL2591 in the tsl2591_setup function, which fails:

static int tsl2591_setup(const struct device *dev)
{
.
.
    ret = tsl2591_reg_write(dev, TSL2591_REG_CONFIG, TSL2591_SRESET);
    if (ret < 0) {
        LOG_ERR("Failed to reset device");
        return ret;
    }
.
.
}

The question is now: Why is the driver failing when it attempts to write the CONFIG register, explicitly setting the RESET bit? 

If we review the TSL2591 datasheet (found here: https://cdn-shop.adafruit.com/datasheets/TSL25911_...), we can see that the CONFIG (or really the CONTROL register is used to reset the device):

Thus, we can focus our investigation when resetting the device.

Using GDB

GDB can be invoked from West by executing the following command:

$> west debug

After executing the above command, GDB is launched and we will be presented with the following interface:

(gdb)

We will be using the following GDB commands and key combinations in the remainder of the blog post:

• break: This command sets a breakpoint. We can give a function or line in a source file to this command.
• r: This command restarts the application.
  
• n: This command steps through the following line of code.
  
• s: This command steps into the following function.
  
• Ctrl-X, A: This key combination presents the Text User Interface (TUI) of GDB. This mode is useful to navigate lines of source code near our current location.
  
• p: Print a variable's value.
  

After entering GDB, we can place a breakpoint on line 423 of the driver source code by executing the following command:

(gdb) break tsl2591.c:423
Breakpoint 1 at 0x800719e: tsl2591.c:423. (2 locations)
Note: automatically using hardware breakpoints for read-only addresses.

Then, we can execute the following command to start the debugging session:

(gdb) r
The program being debugged has already been started.
Start it from the beginning? (y or n) y

We should then see GDB pause with the following output, meaning it has hit our breakpoint:

Breakpoint 1, tsl2591_setup (dev=0x8011488 <__device_dts_ord_100>) at /home/mab/embeddedrelated/tsl2591-clean/zephyr/drivers/sensor/ams/tsl2591/tsl2591.c:423
423                     LOG_ERR("Failed to reset device");

If we hit the Ctrl-X + A key combination, we should see the TUI interface as shown in the image below. We can see the utility of such an interface. We can see the lines surrounding our breakpoint, which is useful for debugging.

We can see from the image above that the reset operation happens on line 421, and we can set a breakpoint there to debug further and restart the session (we may also want to exit TUI mode so the text is less intrusive):

(gdb) break tsl2591.c:421
(gdb) r
The program being debugged has been started already.
Start it from the beginning? (y or n

After restarting the session, GDB stops at the breakpoint we just entered:

Breakpoint 2, tsl2591_setup (dev=0x8011488 <__device_dts_ord_100>) at /home/mab/embeddedrelated/tsl2591-clean/zephyr/drivers/sensor/ams/tsl2591/tsl2591.c:421
421             ret = tsl2591_reg_write(dev, TSL2591_REG_CONFIG, TSL2591_SRESET);

We can use the s command to enter the tsl2591_reg_write function:

(gdb) s
Info : halted: PC: 0x08007194
halted: PC: 0x08007194
Info : halted: PC: 0x08007196
halted: PC: 0x08007196
Info : halted: PC: 0x0800df50
halted: PC: 0x0800df50
tsl2591_reg_write (reg=reg@entry=1 '\001', val=val@entry=128 '\200', dev=<optimized out>) at /home/mab/embeddedrelated/tsl2591-clean/zephyr/drivers/sensor/ams/tsl2591/tsl2591.c:24
24      static int tsl2591_reg_write(const struct device *dev, uint8_t reg, uint8_t val)

We can continue to use the s command in GDB to trace through Zephyr's i2c subsystem. Eventually, we will arrive at the point where the i2c subsystem calls into the appropriate function of the i2c controller driver. This is shown below:

(gdb) s
z_impl_i2c_transfer (addr=41, num_msgs=1 '\001', msgs=0x20003334 <z_main_stack+948>, dev=0x8011474 <__device_dts_ord_20>)
    at /home/mab/embeddedrelated/tsl2591-clean/zephyr/include/zephyr/drivers/i2c.h:788
788             int res =  api->transfer(dev, msgs, num_msgs, addr);
(gdb) s
Info : halted: PC: 0x0800df72
halted: PC: 0x0800df72
Info : halted: PC: 0x0800df74
halted: PC: 0x0800df74
Info : halted: PC: 0x0800df76
halted: PC: 0x0800df76
Info : halted: PC: 0x0800df78
halted: PC: 0x0800df78
Info : halted: PC: 0x0800ddce
halted: PC: 0x0800ddce
i2c_stm32_transfer (dev=0x8011474 <__device_dts_ord_20>, msg=0x20003334 <z_main_stack+948>, num_msgs=1 '\001', slave=41) at /home/mab/embeddedrelated/tsl2591-clean/zephyr/drivers/i2c/i2c_ll_stm32.c:143
143             struct i2c_stm32_data *data = dev->data;

As seen above, eventually, the appropriate call is made into the STM32 i2c controller driver. If we enter TUI mode, we can see that the exact function is i2c_stm32_transfer:

If we continue to step through this function (using the n command in GDB), we will eventually reach the stm32_i2c_msg_write function:

We want to enter this function with the s command in GDB. However, if we use the n command in GDB to step through the stm32_i2c_msg_write function, we notice that GDB jumps back to the calling function after stepping through a few lines of the stm32_i2c_msg_write function. If we use the s command, we notice that GDB is back in the stm32_i2c_msg_write function, as shown below:

The reason GDB is jumping between functions is that the compiler is modifying the order of the eventual instructions to the CPU to improve performance. Unfortunately, this can make debugging difficult. Luckily, we can add the following to our prj.conf to instruct the compiler to not perform any optimizations:

[zephyr-tsl2591.git] $> git diff
diff --git a/app/prj.conf b/app/prj.conf
index 1fddfb1..a4cd6b2 100644
--- a/app/prj.conf
+++ b/app/prj.conf
@@ -3,3 +3,4 @@ CONFIG_TSL2591=y
 CONFIG_SHELL=y
 CONFIG_I2C_SHELL=y
 CONFIG_LOG=y
+CONFIG_NO_OPTIMIZATIONS=y

After disabling optimizations, rebuilding the application, flashing it to our board, and starting a new debug session, stepping through the code is much easier, since we're not jumping around different functions. We can add a breakpoint to the start of the stm32_i2c_msg_write function and step through it until we get to line 608, which seems to be the crux of the issue, as shown in the image below (which is in GDB TUI mode):

Based on the conditions of the if statement, we can check the data variable to see if any of the conditions are true using the p command. However, since data is a pointer, we will need to dereference it, as shown below:

(gdb) p *data
$3 = {device_sync_sem = {wait_q = {waitq = {{head = 0x2000176c <i2c_stm32_dev_data_0>, next = 0x2000176c <i2c_stm32_dev_data_0>}, {tail = 0x2000176c <i2c_stm32_dev_data_0>,
          prev = 0x2000176c <i2c_stm32_dev_data_0>}}}, count = 0, limit = 4294967295, poll_events = {{head = 0x2000177c <i2c_stm32_dev_data_0+16>,
        next = 0x2000177c <i2c_stm32_dev_data_0+16>}, {tail = 0x2000177c <i2c_stm32_dev_data_0+16>, prev = 0x2000177c <i2c_stm32_dev_data_0+16>}}}, bus_mutex = {wait_q = {waitq = {{
          head = 0x20001784 <i2c_stm32_dev_data_0+24>, next = 0x20001784 <i2c_stm32_dev_data_0+24>}, {tail = 0x20001784 <i2c_stm32_dev_data_0+24>,
          prev = 0x20001784 <i2c_stm32_dev_data_0+24>}}}, count = 0, limit = 1, poll_events = {{head = 0x20001794 <i2c_stm32_dev_data_0+40>, next = 0x20001794 <i2c_stm32_dev_data_0+40>}, {
        tail = 0x20001794 <i2c_stm32_dev_data_0+40>, prev = 0x20001794 <i2c_stm32_dev_data_0+40>}}}, dev_config = 18, current_timing = {periph_clock = 0, i2c_speed = 0,
    timing_setting = 0}, current = {is_write = 1, is_arlo = 0, is_nack = 1, is_err = 0, msg = 0x20003590 <z_main_stack+528>, len = 0, buf = 0x20003682 <z_main_stack+770> ""},
  is_configured = true, smbalert_active = false, mode = I2CSTM32MODE_I2C}

As we can see above, data->current.is_nack is set to 1, meaning that the controller didn't receive an ACK from the device! Is our hardware faulty, or is the driver incorrect in checking the return when we reset the device?

Well, if we look at Adafruit's Arduino driver (https://github.com/adafruit/Adafruit_TSL2591_Libra...) and the TSL2591 driver in the Linux kernel (https://elixir.bootlin.com/linux/v6.15.9/source/dr...), we can see that neither driver resets the device on startup. We can keep the reset in the Zephyr driver for the TSL2591, but let's not check for the return code (it could be that after a reset, the device doesn't send back an ACK since it might be restarting). 

I submitted this fix as a Github PR in Zephyr and the maintainers also agreed with my assessment. As I mentioned, you can see the exchange here: https://github.com/zephyrproject-rtos/zephyr/pull/...

Happy coding!

Sign in