Systemview broken on SDK 2.8.0/Kernel 3.7.99

[anthony32086]

With the recent release of SDK 2.8.0 enabling tracing with Segger Systemview locks up the system.

The offending issue is buf = net_buf_alloc(&hci_cmd_pool, K_FOREVER); which will block forever waiting for a buffer that will never become available. I am not sure if this is a NRF related change on other parts or a Zephyr but as I am using NCS I felt to report here first.

The following command builds on 2.8.0 and 2.7.0 without fail.

west build -b nrf5340dk/nrf5340/cpuapp --pristine=always nrf/samples/bluetooth/peripheral_bms

However only with 2.8.0 when tracing and systemview are enabled the LED no longer blinks and in Ozone I can trace and see it is stuck in the above line waiting.

west build -b nrf5340dk/nrf5340/cpuapp --pristine=always nrf/samples/bluetooth/peripheral_bms -- -DCONFIG_TRACING=y -DCONFIG_SEGGER_SYSTEMVIEW=y

[Susheel Nuguru]

Just compiled this for nrf5340dk_nrf5340_cpuapp and running the debugger shows that it is not stuck at the shown function call that you pointed out.

Tested on v2.8.0,  Not sure what is different on your end by try increasing the main stack size in case the 1024 bytes might be a border without enabling trace and systemview and when you enable it, it might cross that usage and causing some stack corruption.

Add this in your prj.conf and pristine build it.

CONFIG_MAIN_STACK_SIZE=2048

[anthony32086]

I've tried increasing the stack to 2048, and even 8192 for botth system workq and main stack both without success.I've also tried CONFIG_SEGGER_RTT_BUFFER_SIZE_UP=8192 and CONFIG_SEGGER_SYSVIEW_RTT_BUFFER_SIZE=8192 which did not work.

Interestingly I now get it to fail at k_fifo_put(&bt_dev.cmd_tx_queue, net_buf_ref(buf)); instead.Specifically the system is not locked up but when bt_tx_irq_raise() submit's it's work the system is stuck in endless idle waiting for something to complete.

Replacing sys_port_trace_k_fifo_put_enter and sys_port_trace_k_fifo_put_exit with empty macros resolves the issue completely which makes me agree that sysview is doing something weird with buffer overruns corrupting the stack.

[Susheel Nuguru]

Yes, I agree with you, it looks like systemviewer is doing something with the buffer use. I do not see the same thing that you see and I am on latest version. Maybe there are some timing issues aswell. It is good that you are trying to get the whole picture of your application with systermviewer. Very few developers/architects do that these days. If you are unblocked with this workaround, then it should be good, just do not forget to undo this workaround in your release version.

[anthony32086]

So turns out this is a zephyr bug from commit 69fe9b0 which replaced the function call net_buf_put with a macro call k_fifo_put.

The problem being the second argument is a function call which gets repeated by preprocessor resulting in a double increment of the reference counter, which is unable to be freed.

Removing the function from the macro and setting a temporary value solves the problem.

[anthony32086]

Also a quick regex check with "k_fifo_put\(.*\(" shows there are several instances in the kernel where this happens, some of which will yield memory leaks when tracing is enabled. I would say every utilization of all the tracing macros should be looked at.

Some samples:

zephyr/subsys/bluetooth/host/hci_core.c

zephyr/subsys/bluetooth/host/classic/rfcomm.c

zephyr/subsys/bluetooth/mesh/adv.c

[Hieu]

Hi anthony32086,

Thank you for the detailed report. I want to let you know that it has been relayed to our R&D team. The issue will be investigated and corrected.

Hieu

[bearsh]

Hi Hieu 

Has this issue been fixed in the meantime? Is there a public issue to follow?

[Hieu]

Hi bearsh ,

It seems anthony32086 created a fix which has been merged in Zephyr upstream: https://github.com/zephyrproject-rtos/zephyr/pull/82828.

It doesn't seem to have been merge into NCS's Zephyr downstream yet, but you can create a patch from that pull request and patch the Zephyr repository yourself, if you need it.